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

1

tests

0

failures

0

ignored

2.183s

duration

100%

successful

Tests

Test Duration Result
testEvilC 2.183s passed

Standard error

29-5-19 15:05:46.797 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:46.800 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
29-5-19 15:05:46.826 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:46.827 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:46.827 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:46.827 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:46.870 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-5-19 15:05:46.871 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-5-19 15:05:46.885 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-5-19 15:05:46.889 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-5-19 15:05:46.890 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-5-19 15:05:46.897 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-5-19 15:05:46.897 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-5-19 15:05:46.897 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-5-19 15:05:46.897 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-5-19 15:05:46.905 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.908 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.911 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.915 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.918 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.921 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.925 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.932 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:46.935 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-5-19 15:05:46.937 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-5-19 15:05:46.940 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-5-19 15:05:46.942 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-5-19 15:05:46.942 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-5-19 15:05:46.943 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-5-19 15:05:46.946 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-5-19 15:05:46.950 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-5-19 15:05:46.952 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-5-19 15:05:46.955 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-5-19 15:05:46.957 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-5-19 15:05:46.959 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-5-19 15:05:46.959 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-5-19 15:05:46.962 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-5-19 15:05:46.967 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-5-19 15:05:46.970 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-5-19 15:05:46.973 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-5-19 15:05:46.973 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-5-19 15:05:46.975 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-5-19 15:05:46.979 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-5-19 15:05:46.979 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-5-19 15:05:46.979 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-5-19 15:05:46.982 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:46.982 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-5-19 15:05:46.982 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:46.982 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@4a7f753) ...
29-5-19 15:05:46.983 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:46.983 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:46.983 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-5-19 15:05:46.983 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:46.983 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-5-19 15:05:46.983 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:46.983 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@1d94f927) ...
29-5-19 15:05:46.984 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-A ...
29-5-19 15:05:46.984 | StatusOperation | Test worker    | FINE : - New file: A1
29-5-19 15:05:46.984 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:46.984 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@695e5232) ...
29-5-19 15:05:46.984 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:46.985 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:46.985 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:46.985 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-5-19 15:05:46.985 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:46.985 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@43fa27cb) ...
29-5-19 15:05:46.985 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:46.986 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@60c98443) ...
29-5-19 15:05:46.986 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-5-19 15:05:46.986 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1559142346827] ...
29-5-19 15:05:46.986 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1559142346827]
29-5-19 15:05:46.986 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1559142346827] ...
29-5-19 15:05:46.987 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:46.994 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-5-19 15:05:46.994 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-5-19 15:05:46.995 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@548532d2) ...
29-5-19 15:05:46.995 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-5-19 15:05:46.995 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-190529150340085-42928-client-A/A1
29-5-19 15:05:46.995 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-190529150340085-42928-client-A/A1
29-5-19 15:05:47.037 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 403782c823a78e235302358812b38284f93c7a5b
29-5-19 15:05:47.037 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk ed5f75f681efa1ad0a172d7ced64aca93a2a3093
29-5-19 15:05:47.038 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 403782c823a78e235302358812b38284f93c7a5b > ed5f75f681efa1ad0a172d7ced64aca93a2a3093
29-5-19 15:05:47.038 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 403782c823a78e235302358812b38284f93c7a5b > /tmp/syncanytest/syncany-190529150340085-42928-client-A/A1
29-5-19 15:05:47.038 | Indexer         | AsyncI/syncany | FINE : - /File: A1 (checksum 403782c823a78e235302358812b38284f93c7a5b)
29-5-19 15:05:47.042 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A1, checksum: 403782c823a78e235302358812b38284f93c7a5b)
29-5-19 15:05:47.042 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A1
29-5-19 15:05:47.042 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:46 UTC 2019, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.042 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-5-19 15:05:47.042 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@21414204) ...
29-5-19 15:05:47.044 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk ed5f75f681efa1ad0a172d7ced64aca93a2a3093
29-5-19 15:05:47.044 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@18da9369) ...
29-5-19 15:05:47.044 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142346994, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:47.045 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-5-19 15:05:47.045 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
29-5-19 15:05:47.046 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-5-19 15:05:47.046 | UpOperation     | Test worker    | INFO : - Uploading multichunk ed5f75f681efa1ad0a172d7ced64aca93a2a3093 from /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093 to RemoteFile[name=multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093] ...
29-5-19 15:05:47.046 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093 -> Temp. remote file: RemoteFile[name=temp-SkQLd-multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093], final location: RemoteFile[name=multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093]
29-5-19 15:05:47.046 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1559142347046, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:47.046 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1559142347046 to file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000001 ... 
29-5-19 15:05:47.046 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000001 ...
29-5-19 15:05:47.047 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-5-19 15:05:47.047 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
29-5-19 15:05:47.047 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-EfawQ-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
29-5-19 15:05:47.048 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-5-19 15:05:47.048 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-5-19 15:05:47.049 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@3482d4cb) ...
29-5-19 15:05:47.049 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/temp-transaction-17098028012860697094.tmp
29-5-19 15:05:47.050 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@5b09c4f) ...
29-5-19 15:05:47.050 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-87f351d] ...
29-5-19 15:05:47.056 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-5-19 15:05:47.056 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@79595eb3) ...
29-5-19 15:05:47.056 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093 to temp. file RemoteFile[name=temp-SkQLd-multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093] ...
29-5-19 15:05:47.056 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@4a805a53) ...
29-5-19 15:05:47.057 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-EfawQ-database-A-0000000001] ...
29-5-19 15:05:47.058 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-SkQLd-multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093] to final location RemoteFile[name=multichunk-ed5f75f681efa1ad0a172d7ced64aca93a2a3093] ...
29-5-19 15:05:47.058 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-EfawQ-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
29-5-19 15:05:47.058 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-87f351d] ...
29-5-19 15:05:47.058 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-5-19 15:05:47.058 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-5-19 15:05:47.059 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1559142347046) ...
29-5-19 15:05:47.063 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-5-19 15:05:47.076 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1559142347046, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:47.076 | UpOperation     | Test worker    | INFO : Committing local database.
29-5-19 15:05:47.076 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-5-19 15:05:47.079 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-5-19 15:05:47.080 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347079, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-5-19 15:05:47.080 | UpOperation     | Test worker    | INFO : Sync up done.
29-5-19 15:05:47.082 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1559142346827] ...
29-5-19 15:05:47.090 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1559142346827]
29-5-19 15:05:47.090 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:47.090 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:47.090 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@32348772) ...
29-5-19 15:05:47.094 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.094 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:47.094 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.094 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.094 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.094 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.094 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.094 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.094 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.095 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.095 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.095 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:47.095 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.095 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.095 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:47.095 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:47.095 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.095 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.095 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.095 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.095 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.095 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.095 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:47.095 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:47.105 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.105 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:47.105 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-5-19 15:05:47.105 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.105 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@67c9651f) ...
29-5-19 15:05:47.114 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.115 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:47.115 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-5-19 15:05:47.115 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.115 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-5-19 15:05:47.115 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:47.115 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@57f2ca90) ...
29-5-19 15:05:47.116 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-A ...
29-5-19 15:05:47.116 | StatusOperation | Test worker    | FINE : - New file: A2
29-5-19 15:05:47.116 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:47.116 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4f1b6364) ...
29-5-19 15:05:47.116 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:47.117 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.117 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:47.117 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-5-19 15:05:47.117 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.117 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@1ed7c201) ...
29-5-19 15:05:47.117 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:47.117 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:47.117 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@61a6ea81) ...
29-5-19 15:05:47.118 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-5-19 15:05:47.118 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1559142347095] ...
29-5-19 15:05:47.118 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1559142347095]
29-5-19 15:05:47.118 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1559142347095] ...
29-5-19 15:05:47.122 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.130 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-5-19 15:05:47.135 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-5-19 15:05:47.135 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@65788ba) ...
29-5-19 15:05:47.135 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-5-19 15:05:47.140 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A1, type=FILE, status=DELETED, size=51200, lastModified=Wed May 29 15:05:46 UTC 2019, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.140 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:46 UTC 2019, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.140 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-190529150340085-42928-client-A/A2
29-5-19 15:05:47.140 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-190529150340085-42928-client-A/A2
29-5-19 15:05:47.144 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 403782c823a78e235302358812b38284f93c7a5b
29-5-19 15:05:47.144 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 403782c823a78e235302358812b38284f93c7a5b > /tmp/syncanytest/syncany-190529150340085-42928-client-A/A2
29-5-19 15:05:47.144 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum 403782c823a78e235302358812b38284f93c7a5b)
29-5-19 15:05:47.145 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 446e4a2a3af666d29ce82b1a3cb268d5189ca01e (by checksum: 403782c823a78e235302358812b38284f93c7a5b), appending new version.
29-5-19 15:05:47.146 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A2, but actual PATH = A1, for file A1
29-5-19 15:05:47.146 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:46 UTC 2019, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.146 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:46 UTC 2019, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.146 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@35d77510) ...
29-5-19 15:05:47.147 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@1c5070de) ...
29-5-19 15:05:47.148 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347135, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.148 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@79751671) ...
29-5-19 15:05:47.148 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-5-19 15:05:47.148 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
29-5-19 15:05:47.148 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-5-19 15:05:47.149 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1559142347148, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.149 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1559142347148 to file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000002 ... 
29-5-19 15:05:47.149 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000002 ...
29-5-19 15:05:47.150 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-5-19 15:05:47.150 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
29-5-19 15:05:47.150 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-GtTmr-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
29-5-19 15:05:47.151 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-5-19 15:05:47.151 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-5-19 15:05:47.152 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-5-19 15:05:47.153 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/temp-transaction-15633897914314521286.tmp
29-5-19 15:05:47.153 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@37773be9) ...
29-5-19 15:05:47.153 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-1053b035] ...
29-5-19 15:05:47.154 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-5-19 15:05:47.154 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@f405500) ...
29-5-19 15:05:47.154 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-GtTmr-database-A-0000000002] ...
29-5-19 15:05:47.163 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-GtTmr-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
29-5-19 15:05:47.163 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-1053b035] ...
29-5-19 15:05:47.164 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-5-19 15:05:47.164 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-5-19 15:05:47.164 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1559142347148) ...
29-5-19 15:05:47.166 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-5-19 15:05:47.177 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1559142347148, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.177 | UpOperation     | Test worker    | INFO : Committing local database.
29-5-19 15:05:47.177 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-5-19 15:05:47.177 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347152, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-5-19 15:05:47.177 | UpOperation     | Test worker    | INFO : Sync up done.
29-5-19 15:05:47.179 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1559142347095] ...
29-5-19 15:05:47.186 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1559142347095]
29-5-19 15:05:47.186 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:47.186 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:47.186 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@42853653) ...
29-5-19 15:05:47.187 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.187 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:47.187 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.187 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.187 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.187 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.187 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.187 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.187 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.187 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.187 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.188 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:47.188 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.188 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.188 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:47.188 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:47.188 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.188 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.188 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.188 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.188 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.188 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.188 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:47.188 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:47.192 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.192 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:47.192 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-5-19 15:05:47.192 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.192 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6b02d0c3) ...
29-5-19 15:05:47.193 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.193 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:47.193 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-5-19 15:05:47.193 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.193 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-5-19 15:05:47.193 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:47.193 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@1906b7c3) ...
29-5-19 15:05:47.195 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-A ...
29-5-19 15:05:47.195 | StatusOperation | Test worker    | FINE : - New file: A3
29-5-19 15:05:47.196 | FileVersionComp | Test worker    | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = 403782c823a78e235302358812b38284f93c7a5b, but actual CHECKSUM = a51caf4ed139d016ac8b60e10a533a906e2a13c5, for file A2
29-5-19 15:05:47.196 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:47.196 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@125e8e35) ...
29-5-19 15:05:47.196 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:47.197 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.197 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:47.197 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-5-19 15:05:47.197 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.197 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@71b0d715) ...
29-5-19 15:05:47.197 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:47.198 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:47.198 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:47.198 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@33152e11) ...
29-5-19 15:05:47.198 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-5-19 15:05:47.198 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1559142347188] ...
29-5-19 15:05:47.198 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1559142347188]
29-5-19 15:05:47.199 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1559142347188] ...
29-5-19 15:05:47.199 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.218 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-5-19 15:05:47.222 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-5-19 15:05:47.222 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@67e0316e) ...
29-5-19 15:05:47.222 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-5-19 15:05:47.222 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-190529150340085-42928-client-A/A3
29-5-19 15:05:47.223 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-190529150340085-42928-client-A/A3
29-5-19 15:05:47.224 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 474def2a9811b6928ec7d88632e2a7be551a2ed5
29-5-19 15:05:47.224 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 2e76478935a75b6e1409147ad9e22218c599b047
29-5-19 15:05:47.225 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 474def2a9811b6928ec7d88632e2a7be551a2ed5 > 2e76478935a75b6e1409147ad9e22218c599b047
29-5-19 15:05:47.225 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 474def2a9811b6928ec7d88632e2a7be551a2ed5 > /tmp/syncanytest/syncany-190529150340085-42928-client-A/A3
29-5-19 15:05:47.225 | Indexer         | AsyncI/syncany | FINE : - /File: A3 (checksum 474def2a9811b6928ec7d88632e2a7be551a2ed5)
29-5-19 15:05:47.226 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A3, checksum: 474def2a9811b6928ec7d88632e2a7be551a2ed5)
29-5-19 15:05:47.234 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A3
29-5-19 15:05:47.234 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.234 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-5-19 15:05:47.234 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@5389e7b7) ...
29-5-19 15:05:47.235 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-190529150340085-42928-client-A/A2
29-5-19 15:05:47.235 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-190529150340085-42928-client-A/A2
29-5-19 15:05:47.236 | Indexer         | AsyncI/syncany | FINE : - Chunk new: a51caf4ed139d016ac8b60e10a533a906e2a13c5
29-5-19 15:05:47.237 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: a51caf4ed139d016ac8b60e10a533a906e2a13c5 > 2e76478935a75b6e1409147ad9e22218c599b047
29-5-19 15:05:47.237 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: a51caf4ed139d016ac8b60e10a533a906e2a13c5 > /tmp/syncanytest/syncany-190529150340085-42928-client-A/A2
29-5-19 15:05:47.237 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum a51caf4ed139d016ac8b60e10a533a906e2a13c5)
29-5-19 15:05:47.254 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 446e4a2a3af666d29ce82b1a3cb268d5189ca01e (by path: A2), appending new version.
29-5-19 15:05:47.254 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = a51caf4ed139d016ac8b60e10a533a906e2a13c5, but actual CHECKSUM = 403782c823a78e235302358812b38284f93c7a5b, for file A2
29-5-19 15:05:47.254 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.254 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:46 UTC 2019, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.255 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 2e76478935a75b6e1409147ad9e22218c599b047
29-5-19 15:05:47.255 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@62a4876c) ...
29-5-19 15:05:47.255 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347222, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-5-19 15:05:47.255 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@22c7655d) ...
29-5-19 15:05:47.256 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-5-19 15:05:47.256 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
29-5-19 15:05:47.257 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-5-19 15:05:47.257 | UpOperation     | Test worker    | INFO : - Uploading multichunk 2e76478935a75b6e1409147ad9e22218c599b047 from /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/multichunk-2e76478935a75b6e1409147ad9e22218c599b047 to RemoteFile[name=multichunk-2e76478935a75b6e1409147ad9e22218c599b047] ...
29-5-19 15:05:47.257 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/multichunk-2e76478935a75b6e1409147ad9e22218c599b047 -> Temp. remote file: RemoteFile[name=temp-KeEnp-multichunk-2e76478935a75b6e1409147ad9e22218c599b047], final location: RemoteFile[name=multichunk-2e76478935a75b6e1409147ad9e22218c599b047]
29-5-19 15:05:47.257 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1559142347257, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-5-19 15:05:47.257 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1559142347257 to file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000003 ... 
29-5-19 15:05:47.257 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000003 ...
29-5-19 15:05:47.259 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-5-19 15:05:47.259 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
29-5-19 15:05:47.259 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-kslIS-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
29-5-19 15:05:47.259 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-5-19 15:05:47.260 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-5-19 15:05:47.262 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/temp-transaction-2389419480366833231.tmp
29-5-19 15:05:47.262 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@4b5f0b35) ...
29-5-19 15:05:47.262 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-4fd9ceb2] ...
29-5-19 15:05:47.266 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-5-19 15:05:47.266 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1d19a4e2) ...
29-5-19 15:05:47.266 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/multichunk-2e76478935a75b6e1409147ad9e22218c599b047 to temp. file RemoteFile[name=temp-KeEnp-multichunk-2e76478935a75b6e1409147ad9e22218c599b047] ...
29-5-19 15:05:47.267 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-5-19 15:05:47.267 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@2c2eb3d2) ...
29-5-19 15:05:47.267 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-kslIS-database-A-0000000003] ...
29-5-19 15:05:47.267 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-KeEnp-multichunk-2e76478935a75b6e1409147ad9e22218c599b047] to final location RemoteFile[name=multichunk-2e76478935a75b6e1409147ad9e22218c599b047] ...
29-5-19 15:05:47.268 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-kslIS-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
29-5-19 15:05:47.268 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-4fd9ceb2] ...
29-5-19 15:05:47.268 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-5-19 15:05:47.268 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-5-19 15:05:47.268 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1559142347257) ...
29-5-19 15:05:47.271 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-5-19 15:05:47.293 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1559142347257, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-5-19 15:05:47.293 | UpOperation     | Test worker    | INFO : Committing local database.
29-5-19 15:05:47.293 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-5-19 15:05:47.293 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347267, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-5-19 15:05:47.293 | UpOperation     | Test worker    | INFO : Sync up done.
29-5-19 15:05:47.296 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1559142347188] ...
29-5-19 15:05:47.302 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1559142347188]
29-5-19 15:05:47.302 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:47.302 | Cache           | Test worker    | INFO : Cache size okay (154 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:47.303 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@6884e2a3) ...
29-5-19 15:05:47.303 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.303 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:47.303 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.303 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.303 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.303 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.303 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.303 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.303 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.303 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.303 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.304 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:47.304 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.304 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.304 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:47.304 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:47.304 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.304 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.304 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.304 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.304 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.304 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.304 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:47.304 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:47.315 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.315 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:47.315 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-5-19 15:05:47.315 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.315 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@718f7ed5) ...
29-5-19 15:05:47.316 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.316 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:47.316 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-5-19 15:05:47.316 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.316 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-5-19 15:05:47.316 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:47.316 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@5b9409d0) ...
29-5-19 15:05:47.317 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-A ...
29-5-19 15:05:47.318 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:47.318 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4ecbe565) ...
29-5-19 15:05:47.318 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:47.319 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.319 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:47.319 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-5-19 15:05:47.319 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.319 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@44cae01c) ...
29-5-19 15:05:47.320 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:47.320 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:47.320 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:47.320 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:47.320 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@921c183) ...
29-5-19 15:05:47.320 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-5-19 15:05:47.320 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1559142347304] ...
29-5-19 15:05:47.320 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1559142347304]
29-5-19 15:05:47.320 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1559142347304] ...
29-5-19 15:05:47.321 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.330 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-5-19 15:05:47.330 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-5-19 15:05:47.331 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-5-19 15:05:47.332 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.333 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.333 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1559142347331, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.337 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-5-19 15:05:47.338 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3)
29-5-19 15:05:47.339 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-5-19 15:05:47.340 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A4)/T=1559142347339, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.341 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A4)/T=1559142347339 to file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000004 ... 
29-5-19 15:05:47.341 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000004 ...
29-5-19 15:05:47.342 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-5-19 15:05:47.346 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000004 to RemoteFile[name=database-A-0000000004] ...
29-5-19 15:05:47.346 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-iDFVI-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
29-5-19 15:05:47.348 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-5-19 15:05:47.349 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-5-19 15:05:47.349 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-5-19 15:05:47.353 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/temp-transaction-5383881012629917669.tmp
29-5-19 15:05:47.354 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@6f94e8dd) ...
29-5-19 15:05:47.354 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-1893b526] ...
29-5-19 15:05:47.354 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-5-19 15:05:47.354 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@720f4d8e) ...
29-5-19 15:05:47.354 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-iDFVI-database-A-0000000004] ...
29-5-19 15:05:47.355 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-iDFVI-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
29-5-19 15:05:47.358 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-1893b526] ...
29-5-19 15:05:47.361 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-5-19 15:05:47.361 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-5-19 15:05:47.362 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A4)/T=1559142347339) ...
29-5-19 15:05:47.363 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-5-19 15:05:47.373 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A4)/T=1559142347339, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.373 | UpOperation     | Test worker    | INFO : Committing local database.
29-5-19 15:05:47.373 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-5-19 15:05:47.373 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347349, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-5-19 15:05:47.373 | UpOperation     | Test worker    | INFO : Sync up done.
29-5-19 15:05:47.378 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1559142347304] ...
29-5-19 15:05:47.386 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1559142347304]
29-5-19 15:05:47.386 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:47.386 | Cache           | Test worker    | INFO : Cache size okay (155 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:47.386 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@561fc926) ...
29-5-19 15:05:47.387 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.387 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.387 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:47.387 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:47.433 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-5-19 15:05:47.436 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-5-19 15:05:47.457 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-5-19 15:05:47.461 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-5-19 15:05:47.461 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-5-19 15:05:47.469 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-5-19 15:05:47.469 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-5-19 15:05:47.470 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-5-19 15:05:47.470 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-5-19 15:05:47.478 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.484 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.486 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.489 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.492 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.494 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.497 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.500 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:47.502 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-5-19 15:05:47.505 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-5-19 15:05:47.507 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-5-19 15:05:47.509 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-5-19 15:05:47.509 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-5-19 15:05:47.510 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-5-19 15:05:47.514 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-5-19 15:05:47.524 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-5-19 15:05:47.526 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-5-19 15:05:47.529 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-5-19 15:05:47.534 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-5-19 15:05:47.537 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-5-19 15:05:47.537 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-5-19 15:05:47.539 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-5-19 15:05:47.542 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-5-19 15:05:47.545 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-5-19 15:05:47.548 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-5-19 15:05:47.548 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-5-19 15:05:47.552 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-5-19 15:05:47.555 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-5-19 15:05:47.555 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-5-19 15:05:47.555 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-5-19 15:05:47.570 | DownOperation   | Test worker    | INFO : 
29-5-19 15:05:47.570 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-5-19 15:05:47.570 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.570 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@18c1f6b2) ...
29-5-19 15:05:47.570 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:47.571 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.572 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@72176abf) ...
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-5-19 15:05:47.572 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-5-19 15:05:47.572 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@66b27aee) ...
29-5-19 15:05:47.572 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@17c53a7c) ...
29-5-19 15:05:47.572 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1559142347387] ...
29-5-19 15:05:47.572 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1559142347387]
29-5-19 15:05:47.573 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1559142347387] ...
29-5-19 15:05:47.573 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-5-19 15:05:47.573 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000004
29-5-19 15:05:47.573 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@51c51fe8) ...
29-5-19 15:05:47.573 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000002
29-5-19 15:05:47.573 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@6fedd976) ...
29-5-19 15:05:47.574 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000003
29-5-19 15:05:47.574 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@464f7f82) ...
29-5-19 15:05:47.574 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000001
29-5-19 15:05:47.574 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@49b1d219) ...
29-5-19 15:05:47.575 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-5-19 15:05:47.575 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000001 ...
29-5-19 15:05:47.576 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1559142347046
29-5-19 15:05:47.576 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000002 ...
29-5-19 15:05:47.578 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1559142347148
29-5-19 15:05:47.578 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000003 ...
29-5-19 15:05:47.591 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1559142347257
29-5-19 15:05:47.592 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000004 ...
29-5-19 15:05:47.593 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1559142347339
29-5-19 15:05:47.594 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:47.594 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:47.594 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:47.594 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:47.594 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-5-19 15:05:47.594 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339], B=[]}
29-5-19 15:05:47.594 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-5-19 15:05:47.594 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1559142347046
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1559142347148
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1559142347257
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1559142347339
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1559142347046
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1559142347148
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1559142347257
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1559142347339
29-5-19 15:05:47.595 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-5-19 15:05:47.595 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-5-19 15:05:47.595 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339]
29-5-19 15:05:47.595 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-5-19 15:05:47.595 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339]
29-5-19 15:05:47.595 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-5-19 15:05:47.595 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000001 ...
29-5-19 15:05:47.596 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1559142347046
29-5-19 15:05:47.596 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000002 ...
29-5-19 15:05:47.597 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1559142347148
29-5-19 15:05:47.597 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000003 ...
29-5-19 15:05:47.615 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1559142347257
29-5-19 15:05:47.616 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-A-0000000004 ...
29-5-19 15:05:47.617 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1559142347339
29-5-19 15:05:47.617 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-5-19 15:05:47.618 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.619 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-5-19 15:05:47.619 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-5-19 15:05:47.619 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:47.619 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.620 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
29-5-19 15:05:47.620 | 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=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-B/A2
29-5-19 15:05:47.620 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:47.620 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:47.620 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.620 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
29-5-19 15:05:47.620 | 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=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-B/A3
29-5-19 15:05:47.621 | DownOperation   | Test worker    | INFO :   + Adding multichunk 2e76478935a75b6e1409147ad9e22218c599b047 to download list ...
29-5-19 15:05:47.621 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-5-19 15:05:47.621 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@30980417) ...
29-5-19 15:05:47.621 | Downloader      | Test worker    | INFO :   + Downloading multichunk 2e76478935a75b6e1409147ad9e22218c599b047 ...
29-5-19 15:05:47.622 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 2e76478935a75b6e1409147ad9e22218c599b047 ...
29-5-19 15:05:47.622 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 2e76478935a75b6e1409147ad9e22218c599b047 ...
29-5-19 15:05:47.634 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-5-19 15:05:47.638 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:47.638 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-5-19 15:05:47.638 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:47.638 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/temp-reconstructedFileVersion-17632431770135552191.tmp ...
29-5-19 15:05:47.640 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-5-19 15:05:47.640 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-5-19 15:05:47.641 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-5-19 15:05:47.641 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1559142347046, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:47.647 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
29-5-19 15:05:47.647 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1559142347148, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.648 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
29-5-19 15:05:47.648 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1559142347257, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-5-19 15:05:47.663 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
29-5-19 15:05:47.663 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1559142347339, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:47.682 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1559142347387] ...
29-5-19 15:05:47.694 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1559142347387]
29-5-19 15:05:47.694 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:47.694 | Cache           | Test worker    | INFO : Cache size okay (104 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:47.695 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@1e36728a) ...
29-5-19 15:05:47.695 | DownOperation   | Test worker    | INFO : Sync down done.
29-5-19 15:05:47.699 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-A/A2, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/A2, for file tmp/syncanytest/syncany-190529150340085-42928-client-B/A2
29-5-19 15:05:47.700 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.700 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.700 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.700 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.700 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.700 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.700 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.700 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:47.701 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:47.701 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.701 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.701 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.701 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.701 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.701 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.701 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:47.701 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:47.711 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.711 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:47.711 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
29-5-19 15:05:47.711 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.711 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@7398dafd) ...
29-5-19 15:05:47.712 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.712 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:47.712 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
29-5-19 15:05:47.712 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.712 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:47.712 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@7e03819e) ...
29-5-19 15:05:47.713 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-B ...
29-5-19 15:05:47.714 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:47.714 | StatusOperation | Test worker    | FINE : - New file: A4,B1
29-5-19 15:05:47.714 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4a865dbd) ...
29-5-19 15:05:47.714 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:47.715 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:47.715 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@61e78f59) ...
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:47.715 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:47.715 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@39a57236) ...
29-5-19 15:05:47.715 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-5-19 15:05:47.715 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1559142347701] ...
29-5-19 15:05:47.715 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1559142347701]
29-5-19 15:05:47.716 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1559142347701] ...
29-5-19 15:05:47.721 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:47.814 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-5-19 15:05:47.818 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-5-19 15:05:47.818 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@dc9fa0) ...
29-5-19 15:05:47.818 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-5-19 15:05:47.818 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1
29-5-19 15:05:47.819 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1
29-5-19 15:05:47.822 | Indexer         | AsyncI/syncany | FINE : - Chunk new: e555670dcd160e0370544dfcabb1ad489eac7cd2
29-5-19 15:05:47.822 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 46ac653844e1fc50cdca79aeabc6f545762361b9
29-5-19 15:05:47.823 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: e555670dcd160e0370544dfcabb1ad489eac7cd2 > 46ac653844e1fc50cdca79aeabc6f545762361b9
29-5-19 15:05:47.823 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: e555670dcd160e0370544dfcabb1ad489eac7cd2 > /tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1
29-5-19 15:05:47.823 | Indexer         | AsyncI/syncany | FINE : - /File: A4,B1 (checksum e555670dcd160e0370544dfcabb1ad489eac7cd2)
29-5-19 15:05:47.824 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A4,B1, checksum: e555670dcd160e0370544dfcabb1ad489eac7cd2)
29-5-19 15:05:47.825 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A4,B1
29-5-19 15:05:47.825 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:47.825 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-5-19 15:05:47.825 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@98a4dc0) ...
29-5-19 15:05:47.825 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 46ac653844e1fc50cdca79aeabc6f545762361b9
29-5-19 15:05:47.825 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@2a9545c9) ...
29-5-19 15:05:47.826 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347818, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:47.826 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-5-19 15:05:47.827 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4)
29-5-19 15:05:47.827 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-5-19 15:05:47.827 | UpOperation     | Test worker    | INFO : - Uploading multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 from /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9 to RemoteFile[name=multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9] ...
29-5-19 15:05:47.827 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9 -> Temp. remote file: RemoteFile[name=temp-elgCw-multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9], final location: RemoteFile[name=multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9]
29-5-19 15:05:47.827 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A4,B1)/T=1559142347827, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:47.828 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A4,B1)/T=1559142347827 to file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-B-0000000001 ... 
29-5-19 15:05:47.828 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-B-0000000001 ...
29-5-19 15:05:47.828 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-5-19 15:05:47.828 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-B-0000000001 to RemoteFile[name=database-B-0000000001] ...
29-5-19 15:05:47.829 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-B-0000000001 -> Temp. remote file: RemoteFile[name=temp-pjNjb-database-B-0000000001], final location: RemoteFile[name=database-B-0000000001]
29-5-19 15:05:47.829 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-5-19 15:05:47.829 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-5-19 15:05:47.831 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/temp-transaction-4728295941222562444.tmp
29-5-19 15:05:47.831 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@4dd1ba75) ...
29-5-19 15:05:47.831 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-67cfe330] ...
29-5-19 15:05:47.831 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-5-19 15:05:47.832 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@47f25bd2) ...
29-5-19 15:05:47.832 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9 to temp. file RemoteFile[name=temp-elgCw-multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9] ...
29-5-19 15:05:47.832 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@284449f5) ...
29-5-19 15:05:47.832 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-B-0000000001 to temp. file RemoteFile[name=temp-pjNjb-database-B-0000000001] ...
29-5-19 15:05:47.833 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-elgCw-multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9] to final location RemoteFile[name=multichunk-46ac653844e1fc50cdca79aeabc6f545762361b9] ...
29-5-19 15:05:47.842 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-pjNjb-database-B-0000000001] to final location RemoteFile[name=database-B-0000000001] ...
29-5-19 15:05:47.844 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-67cfe330] ...
29-5-19 15:05:47.840 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@12386319) ...
29-5-19 15:05:47.845 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-5-19 15:05:47.845 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-5-19 15:05:47.845 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A4,B1)/T=1559142347827) ...
29-5-19 15:05:47.849 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-5-19 15:05:47.876 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-5-19 15:05:47.880 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A4,B1)/T=1559142347827, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:47.880 | UpOperation     | Test worker    | INFO : Committing local database.
29-5-19 15:05:47.882 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-5-19 15:05:47.882 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142347876, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-5-19 15:05:47.882 | UpOperation     | Test worker    | INFO : Sync up done.
29-5-19 15:05:47.885 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1559142347701] ...
29-5-19 15:05:47.894 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1559142347701]
29-5-19 15:05:47.894 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:47.895 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:47.895 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@7bfdf39d) ...
29-5-19 15:05:47.897 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.898 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.899 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:47.899 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:47.899 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:47.985 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-5-19 15:05:47.985 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-5-19 15:05:48.000 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-5-19 15:05:48.009 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-5-19 15:05:48.010 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-5-19 15:05:48.016 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-5-19 15:05:48.016 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-5-19 15:05:48.017 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-5-19 15:05:48.017 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-5-19 15:05:48.021 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.023 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.026 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.028 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.031 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.036 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.040 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.043 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-5-19 15:05:48.046 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-5-19 15:05:48.048 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-5-19 15:05:48.050 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-5-19 15:05:48.054 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-5-19 15:05:48.054 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-5-19 15:05:48.055 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-5-19 15:05:48.059 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-5-19 15:05:48.062 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-5-19 15:05:48.066 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-5-19 15:05:48.069 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-5-19 15:05:48.072 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-5-19 15:05:48.076 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-5-19 15:05:48.076 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-5-19 15:05:48.092 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-5-19 15:05:48.098 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-5-19 15:05:48.105 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-5-19 15:05:48.109 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-5-19 15:05:48.109 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-5-19 15:05:48.113 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-5-19 15:05:48.116 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-5-19 15:05:48.116 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-5-19 15:05:48.116 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-5-19 15:05:48.119 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:48.119 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-5-19 15:05:48.119 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.119 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@434ddff5) ...
29-5-19 15:05:48.120 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.120 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:48.120 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-5-19 15:05:48.120 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.120 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:48.121 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@17a7df11) ...
29-5-19 15:05:48.121 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-C ...
29-5-19 15:05:48.122 | StatusOperation | Test worker    | FINE : - New file: C1
29-5-19 15:05:48.122 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:48.122 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@5d92f9a0) ...
29-5-19 15:05:48.122 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.123 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.123 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.123 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-5-19 15:05:48.123 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.123 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2111d999) ...
29-5-19 15:05:48.124 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.124 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-5-19 15:05:48.124 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-5-19 15:05:48.124 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-5-19 15:05:48.124 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-5-19 15:05:48.124 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-5-19 15:05:48.124 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4fb999d3) ...
29-5-19 15:05:48.124 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
29-5-19 15:05:48.124 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
29-5-19 15:05:48.125 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@24dff290) ...
29-5-19 15:05:48.125 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.125 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.125 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.126 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.126 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.126 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.132 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.133 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:48.133 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-5-19 15:05:48.133 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.133 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6f1ca91e) ...
29-5-19 15:05:48.133 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.133 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:48.133 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-5-19 15:05:48.133 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.133 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:48.133 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3778f650) ...
29-5-19 15:05:48.135 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-C ...
29-5-19 15:05:48.135 | StatusOperation | Test worker    | FINE : - New file: C1
29-5-19 15:05:48.135 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:48.135 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@48c39cb8) ...
29-5-19 15:05:48.135 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.137 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.137 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.137 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-5-19 15:05:48.137 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.137 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@197af642) ...
29-5-19 15:05:48.137 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.138 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-5-19 15:05:48.138 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-5-19 15:05:48.138 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-5-19 15:05:48.138 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-5-19 15:05:48.138 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-5-19 15:05:48.138 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@57452a31) ...
29-5-19 15:05:48.138 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
29-5-19 15:05:48.138 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
29-5-19 15:05:48.138 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@65c4e7d6) ...
29-5-19 15:05:48.138 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.138 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.138 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.138 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.138 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.138 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.138 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.138 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.138 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.138 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.139 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.139 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.139 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.139 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.139 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.139 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.139 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.139 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.139 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.139 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.139 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.139 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.139 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.139 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.147 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.147 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:48.147 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-5-19 15:05:48.147 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.147 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@1249bad9) ...
29-5-19 15:05:48.148 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.148 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:48.148 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-5-19 15:05:48.149 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.149 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:48.149 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@2e9bae06) ...
29-5-19 15:05:48.151 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-C ...
29-5-19 15:05:48.151 | StatusOperation | Test worker    | FINE : - New file: C1
29-5-19 15:05:48.151 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:48.151 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@298f0f44) ...
29-5-19 15:05:48.153 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.154 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.154 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.154 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-5-19 15:05:48.154 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.154 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6822bddd) ...
29-5-19 15:05:48.154 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.155 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-5-19 15:05:48.155 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-5-19 15:05:48.155 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-5-19 15:05:48.155 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-5-19 15:05:48.155 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-5-19 15:05:48.155 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@6da8dcba) ...
29-5-19 15:05:48.155 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
29-5-19 15:05:48.155 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
29-5-19 15:05:48.155 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@5c0446a0) ...
29-5-19 15:05:48.155 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.155 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.155 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.156 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.156 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.156 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.163 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.163 | DownOperation   | Test worker    | INFO : 
29-5-19 15:05:48.163 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
29-5-19 15:05:48.163 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.164 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@7defd7df) ...
29-5-19 15:05:48.164 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.164 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.164 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.164 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-5-19 15:05:48.164 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.165 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@28c6e4e3) ...
29-5-19 15:05:48.165 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.165 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-5-19 15:05:48.165 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:48.165 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:48.165 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.165 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-5-19 15:05:48.165 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@240b9fdc) ...
29-5-19 15:05:48.165 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@3e56e5b0) ...
29-5-19 15:05:48.165 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1559142348156] ...
29-5-19 15:05:48.165 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1559142348156]
29-5-19 15:05:48.165 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1559142348156] ...
29-5-19 15:05:48.166 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-5-19 15:05:48.166 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-B-0000000001
29-5-19 15:05:48.166 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@31bac2cf) ...
29-5-19 15:05:48.167 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-5-19 15:05:48.167 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-B-0000000001 ...
29-5-19 15:05:48.169 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.174 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.174 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.174 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.175 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.175 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.175 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-5-19 15:05:48.175 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339], B=[B/(A4,B1)/T=1559142347827]}
29-5-19 15:05:48.175 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1559142347046
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1559142347148
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1559142347257
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1559142347339
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1559142347046
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1559142347148
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1559142347257
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1559142347339
29-5-19 15:05:48.175 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.176 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-5-19 15:05:48.176 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-5-19 15:05:48.176 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-5-19 15:05:48.176 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339]
29-5-19 15:05:48.176 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827]
29-5-19 15:05:48.176 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-5-19 15:05:48.176 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A4,B1)/T=1559142347827]
29-5-19 15:05:48.176 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-5-19 15:05:48.176 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-B-0000000001 ...
29-5-19 15:05:48.177 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.177 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-5-19 15:05:48.182 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.183 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-5-19 15:05:48.183 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-5-19 15:05:48.184 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:48.184 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:48.184 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
29-5-19 15:05:48.184 | 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=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-A/A4,B1
29-5-19 15:05:48.184 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.185 | DownOperation   | Test worker    | INFO :   + Adding multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 to download list ...
29-5-19 15:05:48.185 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-5-19 15:05:48.185 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@6e1b871b) ...
29-5-19 15:05:48.185 | Downloader      | Test worker    | INFO :   + Downloading multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 ...
29-5-19 15:05:48.185 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 ...
29-5-19 15:05:48.185 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 ...
29-5-19 15:05:48.190 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-5-19 15:05:48.190 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.190 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-5-19 15:05:48.190 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.191 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/temp-reconstructedFileVersion-14670027064731066946.tmp ...
29-5-19 15:05:48.192 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-5-19 15:05:48.192 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-5-19 15:05:48.192 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
29-5-19 15:05:48.192 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1559142347827, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.215 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1559142348156] ...
29-5-19 15:05:48.221 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1559142348156]
29-5-19 15:05:48.221 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:48.221 | Cache           | Test worker    | INFO : Cache size okay (206 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:48.221 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@3ac7af3a) ...
29-5-19 15:05:48.221 | DownOperation   | Test worker    | INFO : Sync down done.
29-5-19 15:05:48.226 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-A/A2, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/A2, for file tmp/syncanytest/syncany-190529150340085-42928-client-B/A2
29-5-19 15:05:48.228 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1, for file tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1
29-5-19 15:05:48.229 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.229 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.229 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.229 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.229 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.229 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.229 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.229 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.230 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.230 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.230 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.230 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.230 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.230 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.230 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.230 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.249 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.250 | DownOperation   | Test worker    | INFO : 
29-5-19 15:05:48.250 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-5-19 15:05:48.250 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.250 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@5917c542) ...
29-5-19 15:05:48.250 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.261 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.261 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.261 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-5-19 15:05:48.261 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.261 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@25f13634) ...
29-5-19 15:05:48.262 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.262 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-5-19 15:05:48.262 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:48.262 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:48.262 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.262 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.262 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@76eedc78) ...
29-5-19 15:05:48.262 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
29-5-19 15:05:48.262 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@38f5a65b) ...
29-5-19 15:05:48.287 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.287 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.288 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.288 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.288 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.302 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.302 | DownOperation   | Test worker    | INFO : 
29-5-19 15:05:48.302 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
29-5-19 15:05:48.302 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.302 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@62e8b17d) ...
29-5-19 15:05:48.302 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.303 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.303 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7eab99c0) ...
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-5-19 15:05:48.303 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-5-19 15:05:48.303 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@238e5af4) ...
29-5-19 15:05:48.303 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@3e5421c) ...
29-5-19 15:05:48.303 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-C-1559142348288] ...
29-5-19 15:05:48.303 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-C-1559142348288]
29-5-19 15:05:48.303 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-C-1559142348288] ...
29-5-19 15:05:48.304 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-5-19 15:05:48.304 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000004
29-5-19 15:05:48.304 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@27b567b5) ...
29-5-19 15:05:48.304 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000002
29-5-19 15:05:48.304 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@ee924fd) ...
29-5-19 15:05:48.305 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000003
29-5-19 15:05:48.305 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@3a8e907f) ...
29-5-19 15:05:48.305 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000001
29-5-19 15:05:48.305 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@2278c378) ...
29-5-19 15:05:48.305 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-B-0000000001
29-5-19 15:05:48.305 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@2efc804d) ...
29-5-19 15:05:48.306 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-5-19 15:05:48.306 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000001 ...
29-5-19 15:05:48.307 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1559142347046
29-5-19 15:05:48.307 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000002 ...
29-5-19 15:05:48.318 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1559142347148
29-5-19 15:05:48.318 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000003 ...
29-5-19 15:05:48.320 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1559142347257
29-5-19 15:05:48.321 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000004 ...
29-5-19 15:05:48.322 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1559142347339
29-5-19 15:05:48.322 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-B-0000000001 ...
29-5-19 15:05:48.323 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.324 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.324 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.324 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.324 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.324 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.325 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-5-19 15:05:48.325 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339], B=[B/(A4,B1)/T=1559142347827], C=[]}
29-5-19 15:05:48.325 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1559142347046
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1559142347148
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1559142347257
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1559142347339
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1559142347046
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1559142347148
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1559142347257
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1559142347339
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.325 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-5-19 15:05:48.325 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-5-19 15:05:48.325 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827]
29-5-19 15:05:48.325 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-5-19 15:05:48.325 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827]
29-5-19 15:05:48.325 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-5-19 15:05:48.325 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000001 ...
29-5-19 15:05:48.336 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1559142347046
29-5-19 15:05:48.336 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000002 ...
29-5-19 15:05:48.338 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1559142347148
29-5-19 15:05:48.338 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000003 ...
29-5-19 15:05:48.339 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1559142347257
29-5-19 15:05:48.339 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-A-0000000004 ...
29-5-19 15:05:48.340 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1559142347339
29-5-19 15:05:48.340 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-B-0000000001 ...
29-5-19 15:05:48.341 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.341 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-5-19 15:05:48.358 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.359 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:48.360 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
29-5-19 15:05:48.360 | 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=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-C/A4,B1
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:48.360 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
29-5-19 15:05:48.360 | 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=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-C/A2
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:48.360 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:48.361 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
29-5-19 15:05:48.361 | 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=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-C/A3
29-5-19 15:05:48.361 | DownOperation   | Test worker    | INFO :   + Adding multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 to download list ...
29-5-19 15:05:48.362 | DownOperation   | Test worker    | INFO :   + Adding multichunk 2e76478935a75b6e1409147ad9e22218c599b047 to download list ...
29-5-19 15:05:48.362 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-5-19 15:05:48.362 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@a4c0083) ...
29-5-19 15:05:48.362 | Downloader      | Test worker    | INFO :   + Downloading multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 ...
29-5-19 15:05:48.362 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 ...
29-5-19 15:05:48.363 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 46ac653844e1fc50cdca79aeabc6f545762361b9 ...
29-5-19 15:05:48.372 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@410636eb) ...
29-5-19 15:05:48.372 | Downloader      | Test worker    | INFO :   + Downloading multichunk 2e76478935a75b6e1409147ad9e22218c599b047 ...
29-5-19 15:05:48.372 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 2e76478935a75b6e1409147ad9e22218c599b047 ...
29-5-19 15:05:48.373 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 2e76478935a75b6e1409147ad9e22218c599b047 ...
29-5-19 15:05:48.378 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-5-19 15:05:48.378 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.378 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.378 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-5-19 15:05:48.378 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=a51caf4ed139d016ac8b60e10a533a906e2a13c5, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.379 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/temp-reconstructedFileVersion-5811340546380394908.tmp ...
29-5-19 15:05:48.380 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-5-19 15:05:48.380 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:47 UTC 2019, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Wed May 29 15:05:47 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.381 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/temp-reconstructedFileVersion-14278123435979224744.tmp ...
29-5-19 15:05:48.386 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-5-19 15:05:48.386 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-5-19 15:05:48.386 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-5-19 15:05:48.386 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1559142347046, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.388 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
29-5-19 15:05:48.388 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1559142347148, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:48.389 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
29-5-19 15:05:48.389 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1559142347257, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-5-19 15:05:48.404 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
29-5-19 15:05:48.404 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1559142347339, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-5-19 15:05:48.404 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
29-5-19 15:05:48.404 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1559142347827, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.420 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-C-1559142348288] ...
29-5-19 15:05:48.432 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-C-1559142348288]
29-5-19 15:05:48.432 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:48.432 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:48.432 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@7c7910fe) ...
29-5-19 15:05:48.432 | DownOperation   | Test worker    | INFO : Sync down done.
29-5-19 15:05:48.434 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.435 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.435 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.435 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.448 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.448 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:48.448 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-5-19 15:05:48.448 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.448 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@31e71bec) ...
29-5-19 15:05:48.448 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.448 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:48.449 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-5-19 15:05:48.449 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.449 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:48.449 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@431c2607) ...
29-5-19 15:05:48.449 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-A ...
29-5-19 15:05:48.450 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:48.450 | StatusOperation | Test worker    | INFO : - No changes to local database
29-5-19 15:05:48.450 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@768fa0ca) ...
29-5-19 15:05:48.450 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
29-5-19 15:05:48.450 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@40bcdace) ...
29-5-19 15:05:48.451 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.452 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.452 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.452 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.463 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.463 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:48.463 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
29-5-19 15:05:48.463 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.463 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@63f2f056) ...
29-5-19 15:05:48.464 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.464 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:48.464 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
29-5-19 15:05:48.464 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.464 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:48.464 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@4ebc5868) ...
29-5-19 15:05:48.465 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-B ...
29-5-19 15:05:48.465 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:48.466 | StatusOperation | Test worker    | INFO : - No changes to local database
29-5-19 15:05:48.466 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@802f88a) ...
29-5-19 15:05:48.466 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
29-5-19 15:05:48.466 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@43ebee2c) ...
29-5-19 15:05:48.466 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.466 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.466 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.466 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.466 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.466 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.466 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.466 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.466 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.467 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.467 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.467 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.467 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.467 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.467 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.467 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.475 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.475 | UpOperation     | Test worker    | INFO : 
29-5-19 15:05:48.475 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-5-19 15:05:48.475 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.475 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@658dfd4d) ...
29-5-19 15:05:48.476 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.476 | StatusOperation | Test worker    | INFO : 
29-5-19 15:05:48.476 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-5-19 15:05:48.476 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.476 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-5-19 15:05:48.476 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@66d29426) ...
29-5-19 15:05:48.477 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-190529150340085-42928-client-C ...
29-5-19 15:05:48.477 | StatusOperation | Test worker    | FINE : - New file: C1
29-5-19 15:05:48.477 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-5-19 15:05:48.477 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@401bd5be) ...
29-5-19 15:05:48.477 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.478 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.478 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.478 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-5-19 15:05:48.478 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.478 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7caf7322) ...
29-5-19 15:05:48.478 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.479 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-5-19 15:05:48.479 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:48.479 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:48.479 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.479 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.479 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@418a6dee) ...
29-5-19 15:05:48.479 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-5-19 15:05:48.479 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-C-1559142348467] ...
29-5-19 15:05:48.479 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-C-1559142348467]
29-5-19 15:05:48.479 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-C-1559142348467] ...
29-5-19 15:05:48.480 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.494 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-5-19 15:05:48.494 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-5-19 15:05:48.495 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@23305537) ...
29-5-19 15:05:48.495 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-5-19 15:05:48.495 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-190529150340085-42928-client-C/C1
29-5-19 15:05:48.496 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-190529150340085-42928-client-C/C1
29-5-19 15:05:48.569 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 03abf4a89d511abb70a602327916f447170ae358
29-5-19 15:05:48.570 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e
29-5-19 15:05:48.571 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 03abf4a89d511abb70a602327916f447170ae358 > 94f77783abe425c1e98fb7be6cd0a68c48a3de7e
29-5-19 15:05:48.571 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 03abf4a89d511abb70a602327916f447170ae358 > /tmp/syncanytest/syncany-190529150340085-42928-client-C/C1
29-5-19 15:05:48.571 | Indexer         | AsyncI/syncany | FINE : - /File: C1 (checksum 03abf4a89d511abb70a602327916f447170ae358)
29-5-19 15:05:48.576 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: C1, checksum: 03abf4a89d511abb70a602327916f447170ae358)
29-5-19 15:05:48.576 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file C1
29-5-19 15:05:48.576 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:48.576 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-5-19 15:05:48.576 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@119e24bc) ...
29-5-19 15:05:48.577 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e
29-5-19 15:05:48.577 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@62af80ae) ...
29-5-19 15:05:48.577 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142348495, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.577 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-5-19 15:05:48.578 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4,B1)
29-5-19 15:05:48.582 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@25f263df) ...
29-5-19 15:05:48.583 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-5-19 15:05:48.584 | UpOperation     | Test worker    | INFO : - Uploading multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e from /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e to RemoteFile[name=multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e] ...
29-5-19 15:05:48.584 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e -> Temp. remote file: RemoteFile[name=temp-RLlsI-multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e], final location: RemoteFile[name=multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e]
29-5-19 15:05:48.586 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=C/(A4,B1,C1)/T=1559142348583, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.588 | UpOperation     | Test worker    | INFO : Saving local delta database, version C/(A4,B1,C1)/T=1559142348583 to file /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-C-0000000001 ... 
29-5-19 15:05:48.588 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-C-0000000001 ...
29-5-19 15:05:48.589 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-5-19 15:05:48.589 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-C-0000000001 to RemoteFile[name=database-C-0000000001] ...
29-5-19 15:05:48.590 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-C-0000000001 -> Temp. remote file: RemoteFile[name=temp-DLeAx-database-C-0000000001], final location: RemoteFile[name=database-C-0000000001]
29-5-19 15:05:48.590 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-5-19 15:05:48.590 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-5-19 15:05:48.595 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-5-19 15:05:48.599 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/temp-transaction-15924837261564918594.tmp
29-5-19 15:05:48.599 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@741a07ea) ...
29-5-19 15:05:48.599 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-1d795166] ...
29-5-19 15:05:48.600 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-5-19 15:05:48.600 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@49aebefa) ...
29-5-19 15:05:48.600 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e to temp. file RemoteFile[name=temp-RLlsI-multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e] ...
29-5-19 15:05:48.601 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@b205348) ...
29-5-19 15:05:48.601 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-190529150340085-42928-client-C/.syncany/cache/database-C-0000000001 to temp. file RemoteFile[name=temp-DLeAx-database-C-0000000001] ...
29-5-19 15:05:48.603 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-RLlsI-multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e] to final location RemoteFile[name=multichunk-94f77783abe425c1e98fb7be6cd0a68c48a3de7e] ...
29-5-19 15:05:48.604 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-DLeAx-database-C-0000000001] to final location RemoteFile[name=database-C-0000000001] ...
29-5-19 15:05:48.604 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-1d795166] ...
29-5-19 15:05:48.606 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-5-19 15:05:48.606 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-5-19 15:05:48.606 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version C/(A4,B1,C1)/T=1559142348583) ...
29-5-19 15:05:48.631 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-5-19 15:05:48.657 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=C/(A4,B1,C1)/T=1559142348583, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.657 | UpOperation     | Test worker    | INFO : Committing local database.
29-5-19 15:05:48.657 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-5-19 15:05:48.657 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1559142348595, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-5-19 15:05:48.657 | UpOperation     | Test worker    | INFO : Sync up done.
29-5-19 15:05:48.661 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-C-1559142348467] ...
29-5-19 15:05:48.671 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-C-1559142348467]
29-5-19 15:05:48.672 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:48.672 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:48.672 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@2e7180f) ...
29-5-19 15:05:48.672 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.672 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:48.672 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.672 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.672 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.672 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.672 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.672 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.672 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.672 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.673 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.673 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-A' ...
29-5-19 15:05:48.673 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.673 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.673 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.673 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.673 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.673 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.673 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.673 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.691 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.691 | DownOperation   | Test worker    | INFO : 
29-5-19 15:05:48.691 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
29-5-19 15:05:48.691 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.691 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@ac2d98d) ...
29-5-19 15:05:48.691 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.692 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.692 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.692 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-5-19 15:05:48.692 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.692 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@11a3a422) ...
29-5-19 15:05:48.693 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.693 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-5-19 15:05:48.693 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:48.693 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:48.693 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
29-5-19 15:05:48.693 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.693 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.693 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3d9f0ffa) ...
29-5-19 15:05:48.693 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@61ccb145) ...
29-5-19 15:05:48.693 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1559142348673] ...
29-5-19 15:05:48.693 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1559142348673]
29-5-19 15:05:48.693 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1559142348673] ...
29-5-19 15:05:48.694 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-5-19 15:05:48.698 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-C-0000000001
29-5-19 15:05:48.698 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@64810b28) ...
29-5-19 15:05:48.699 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-5-19 15:05:48.699 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-C-0000000001 ...
29-5-19 15:05:48.700 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.701 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.701 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.701 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.701 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.701 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.701 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.702 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-5-19 15:05:48.702 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827], C=[C/(A4,B1,C1)/T=1559142348583]}
29-5-19 15:05:48.702 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1559142347046
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1559142347148
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1559142347257
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1559142347339
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1559142347046
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1559142347148
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1559142347257
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1559142347339
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.703 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-5-19 15:05:48.703 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827]
29-5-19 15:05:48.703 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827, C/(A4,B1,C1)/T=1559142348583]
29-5-19 15:05:48.703 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-5-19 15:05:48.703 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1559142348583]
29-5-19 15:05:48.703 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-5-19 15:05:48.703 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/database-C-0000000001 ...
29-5-19 15:05:48.705 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.705 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-5-19 15:05:48.706 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.707 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-5-19 15:05:48.707 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-5-19 15:05:48.707 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:48.707 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:48.718 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
29-5-19 15:05:48.719 | 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=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-A/C1
29-5-19 15:05:48.719 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.720 | DownOperation   | Test worker    | INFO :   + Adding multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e to download list ...
29-5-19 15:05:48.721 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-5-19 15:05:48.722 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@71a3f6fe) ...
29-5-19 15:05:48.722 | Downloader      | Test worker    | INFO :   + Downloading multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e ...
29-5-19 15:05:48.723 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e ...
29-5-19 15:05:48.726 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e ...
29-5-19 15:05:48.726 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-5-19 15:05:48.727 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.727 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-5-19 15:05:48.727 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.727 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-190529150340085-42928-client-A/.syncany/cache/temp-reconstructedFileVersion-17960643350624919833.tmp ...
29-5-19 15:05:48.736 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-5-19 15:05:48.741 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-5-19 15:05:48.746 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
29-5-19 15:05:48.746 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1559142348583, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.768 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1559142348673] ...
29-5-19 15:05:48.777 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1559142348673]
29-5-19 15:05:48.777 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:48.777 | Cache           | Test worker    | INFO : Cache size okay (257 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:48.778 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@2ddf9cd9) ...
29-5-19 15:05:48.778 | DownOperation   | Test worker    | INFO : Sync down done.
29-5-19 15:05:48.778 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.778 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-B' ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.778 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.778 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.779 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.791 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.791 | DownOperation   | Test worker    | INFO : 
29-5-19 15:05:48.791 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-5-19 15:05:48.791 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.791 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@6357cc59) ...
29-5-19 15:05:48.791 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.792 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.792 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@29c59b89) ...
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.792 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.792 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@5e49d9a3) ...
29-5-19 15:05:48.792 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@493bc60a) ...
29-5-19 15:05:48.793 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1559142348779] ...
29-5-19 15:05:48.793 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1559142348779]
29-5-19 15:05:48.793 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1559142348779] ...
29-5-19 15:05:48.793 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-5-19 15:05:48.793 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-C-0000000001
29-5-19 15:05:48.793 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@505a9caa) ...
29-5-19 15:05:48.794 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-5-19 15:05:48.794 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-C-0000000001 ...
29-5-19 15:05:48.796 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.796 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.796 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.796 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.796 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.796 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.796 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-190529150340085-42928-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
29-5-19 15:05:48.797 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-5-19 15:05:48.797 | DownOperation   | Test worker    | INFO : Populated unknown branches: {B=[A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827], C=[C/(A4,B1,C1)/T=1559142348583]}
29-5-19 15:05:48.797 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1559142347046
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1559142347148
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1559142347257
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1559142347339
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1559142347046
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1559142347148
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1559142347257
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1559142347339
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1559142347827
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.797 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-5-19 15:05:48.797 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827]
29-5-19 15:05:48.797 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1559142347046, A/(A2)/T=1559142347148, A/(A3)/T=1559142347257, A/(A4)/T=1559142347339, B/(A4,B1)/T=1559142347827, C/(A4,B1,C1)/T=1559142348583]
29-5-19 15:05:48.797 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-5-19 15:05:48.797 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1559142348583]
29-5-19 15:05:48.797 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-5-19 15:05:48.797 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/database-C-0000000001 ...
29-5-19 15:05:48.810 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1559142348583
29-5-19 15:05:48.814 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-5-19 15:05:48.815 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.816 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-5-19 15:05:48.816 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-5-19 15:05:48.816 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-5-19 15:05:48.816 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-5-19 15:05:48.817 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
29-5-19 15:05:48.817 | 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=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-190529150340085-42928-client-B/C1
29-5-19 15:05:48.817 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.817 | DownOperation   | Test worker    | INFO :   + Adding multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e to download list ...
29-5-19 15:05:48.817 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-5-19 15:05:48.817 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@32d660d5) ...
29-5-19 15:05:48.818 | Downloader      | Test worker    | INFO :   + Downloading multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e ...
29-5-19 15:05:48.822 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e ...
29-5-19 15:05:48.823 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 94f77783abe425c1e98fb7be6cd0a68c48a3de7e ...
29-5-19 15:05:48.830 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-5-19 15:05:48.830 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.830 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-5-19 15:05:48.830 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Wed May 29 15:05:48 UTC 2019, linkTarget=null, checksum=03abf4a89d511abb70a602327916f447170ae358, updated=Wed May 29 15:05:48 UTC 2019, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-5-19 15:05:48.831 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-190529150340085-42928-client-B/.syncany/cache/temp-reconstructedFileVersion-1470943000374990505.tmp ...
29-5-19 15:05:48.851 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-5-19 15:05:48.852 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-5-19 15:05:48.852 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
29-5-19 15:05:48.852 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1559142348583, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-5-19 15:05:48.885 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1559142348779] ...
29-5-19 15:05:48.890 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1559142348779]
29-5-19 15:05:48.890 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-5-19 15:05:48.890 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
29-5-19 15:05:48.890 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@57e5ca8c) ...
29-5-19 15:05:48.891 | DownOperation   | Test worker    | INFO : Sync down done.
29-5-19 15:05:48.891 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.891 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-190529150340085-42928-client-C' ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - With feature Retriable
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - With feature PathAware
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-5-19 15:05:48.891 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-5-19 15:05:48.891 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-5-19 15:05:48.896 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.900 | DownOperation   | Test worker    | INFO : 
29-5-19 15:05:48.900 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
29-5-19 15:05:48.900 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.900 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@67b81f65) ...
29-5-19 15:05:48.902 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-5-19 15:05:48.903 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-5-19 15:05:48.906 | LsRemoteOperati | Test worker    | INFO : 
29-5-19 15:05:48.906 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-5-19 15:05:48.906 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-5-19 15:05:48.906 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6cece959) ...
29-5-19 15:05:48.907 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-5-19 15:05:48.907 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-5-19 15:05:48.907 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-5-19 15:05:48.907 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-5-19 15:05:48.907 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.907 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.907 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-5-19 15:05:48.907 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@16560f77) ...
29-5-19 15:05:48.907 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
29-5-19 15:05:48.907 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@24c6075e) ...
29-5-19 15:05:48.922 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-A/A2, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/A2, for file tmp/syncanytest/syncany-190529150340085-42928-client-B/A2
29-5-19 15:05:48.924 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1, for file tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1
29-5-19 15:05:48.935 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-A/C1, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/C1, for file tmp/syncanytest/syncany-190529150340085-42928-client-B/C1
29-5-19 15:05:48.945 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/A2, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-C/A2, for file tmp/syncanytest/syncany-190529150340085-42928-client-C/A2
29-5-19 15:05:48.953 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/A4,B1, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-C/A4,B1, for file tmp/syncanytest/syncany-190529150340085-42928-client-C/A4,B1
29-5-19 15:05:48.963 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-190529150340085-42928-client-B/C1, but actual PATH = tmp/syncanytest/syncany-190529150340085-42928-client-C/C1, for file tmp/syncanytest/syncany-190529150340085-42928-client-C/C1