Class org.syncany.tests.integration.scenarios.ManyRenamesScenarioTest

1

tests

0

failures

0

ignored

0.618s

duration

100%

successful

Tests

Test Duration Result
testManyRenames 0.618s passed

Standard error

25-5-17 10:18:18.178 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.178 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
25-5-17 10:18:18.185 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.185 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.185 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.185 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.186 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.186 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.186 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.186 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.202 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:18:18.202 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:18:18.212 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:18:18.215 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:18:18.215 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:18:18.220 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:18:18.220 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:18:18.220 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:18:18.220 | 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) ); 
25-5-17 10:18:18.223 | 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 ); 
25-5-17 10:18:18.225 | 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 ); 
25-5-17 10:18:18.228 | 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 ); 
25-5-17 10:18:18.230 | 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 ); 
25-5-17 10:18:18.232 | 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 ); 
25-5-17 10:18:18.234 | 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 ); 
25-5-17 10:18:18.237 | 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 ); 
25-5-17 10:18:18.239 | 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 ); 
25-5-17 10:18:18.241 | 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) ); 
25-5-17 10:18:18.243 | 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) ); 
25-5-17 10:18:18.245 | 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) ); 
25-5-17 10:18:18.248 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:18:18.248 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:18:18.249 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:18:18.251 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:18:18.254 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:18:18.256 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:18:18.258 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:18:18.261 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:18:18.262 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:18:18.263 | 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'; 
25-5-17 10:18:18.265 | 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'; 
25-5-17 10:18:18.268 | 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; 
25-5-17 10:18:18.270 | 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'; 
25-5-17 10:18:18.273 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:18:18.273 | 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; 
25-5-17 10:18:18.276 | 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; 
25-5-17 10:18:18.278 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:18:18.278 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:18:18.278 | 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; 
25-5-17 10:18:18.281 | UpOperation     | Test worker    | INFO : 
25-5-17 10:18:18.281 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:18:18.281 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.281 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2e218fc4) ...
25-5-17 10:18:18.282 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.282 | StatusOperation | Test worker    | INFO : 
25-5-17 10:18:18.282 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:18:18.282 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.282 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:18:18.282 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@2f142def) ...
25-5-17 10:18:18.282 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101612005-63448-client-A ...
25-5-17 10:18:18.283 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:18:18.283 | StatusOperation | Test worker    | FINE : - New file: A-original
25-5-17 10:18:18.283 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4f7435ff) ...
25-5-17 10:18:18.283 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.283 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.283 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.283 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:18:18.283 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.283 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@236a0eaf) ...
25-5-17 10:18:18.284 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.284 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1e53a485) ...
25-5-17 10:18:18.284 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:18:18.284 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707498186] ...
25-5-17 10:18:18.284 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707498186]
25-5-17 10:18:18.284 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707498186] ...
25-5-17 10:18:18.284 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.285 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:18:18.285 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:18:18.285 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@775ac2f4) ...
25-5-17 10:18:18.285 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:18:18.285 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-original
25-5-17 10:18:18.285 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-original
25-5-17 10:18:18.287 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c
25-5-17 10:18:18.287 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 4c8f75a00426ed280b1855da8e564bf1c6e4de19
25-5-17 10:18:18.287 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c > 4c8f75a00426ed280b1855da8e564bf1c6e4de19
25-5-17 10:18:18.287 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c > /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-original
25-5-17 10:18:18.288 | Indexer         | AsyncI/syncany | FINE : - /File: A-original (checksum 286eab6a0bcabc8fb6b685a58bc380f9eda6330c)
25-5-17 10:18:18.288 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A-original, checksum: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c)
25-5-17 10:18:18.288 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A-original
25-5-17 10:18:18.288 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.288 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
25-5-17 10:18:18.288 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@78e9c069) ...
25-5-17 10:18:18.289 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 4c8f75a00426ed280b1855da8e564bf1c6e4de19
25-5-17 10:18:18.289 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@536923e9) ...
25-5-17 10:18:18.289 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498285, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
25-5-17 10:18:18.289 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@3ac26a82) ...
25-5-17 10:18:18.293 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:18:18.293 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
25-5-17 10:18:18.294 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:18:18.294 | UpOperation     | Test worker    | INFO : - Uploading multichunk 4c8f75a00426ed280b1855da8e564bf1c6e4de19 from /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19 to RemoteFile[name=multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19] ...
25-5-17 10:18:18.294 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19 -> Temp. remote file: RemoteFile[name=temp-dzXkU-multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19], final location: RemoteFile[name=multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19]
25-5-17 10:18:18.294 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1495707498294, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
25-5-17 10:18:18.295 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1495707498294 to file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000001 ... 
25-5-17 10:18:18.295 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000001 ...
25-5-17 10:18:18.296 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:18:18.296 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
25-5-17 10:18:18.296 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-dXSwL-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
25-5-17 10:18:18.296 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:18:18.296 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:18:18.296 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:18:18.297 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/temp-transaction-1532986199567543944.tmp
25-5-17 10:18:18.297 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@429f8356) ...
25-5-17 10:18:18.297 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-2d563529] ...
25-5-17 10:18:18.297 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:18:18.297 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@331e444c) ...
25-5-17 10:18:18.297 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19 to temp. file RemoteFile[name=temp-dzXkU-multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19] ...
25-5-17 10:18:18.298 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@11e2e71d) ...
25-5-17 10:18:18.298 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-dXSwL-database-A-0000000001] ...
25-5-17 10:18:18.298 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-dzXkU-multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19] to final location RemoteFile[name=multichunk-4c8f75a00426ed280b1855da8e564bf1c6e4de19] ...
25-5-17 10:18:18.298 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-dXSwL-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
25-5-17 10:18:18.298 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-2d563529] ...
25-5-17 10:18:18.298 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:18:18.298 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:18:18.298 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1495707498294) ...
25-5-17 10:18:18.299 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:18:18.305 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1495707498294, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
25-5-17 10:18:18.305 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:18:18.305 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:18:18.305 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498296, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:18:18.305 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:18:18.308 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707498186] ...
25-5-17 10:18:18.308 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707498186]
25-5-17 10:18:18.308 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.308 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.308 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@6f95c02f) ...
25-5-17 10:18:18.308 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.309 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.309 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.309 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.318 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:18:18.319 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:18:18.327 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:18:18.330 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:18:18.330 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:18:18.335 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:18:18.335 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:18:18.336 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:18:18.336 | 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) ); 
25-5-17 10:18:18.338 | 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 ); 
25-5-17 10:18:18.341 | 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 ); 
25-5-17 10:18:18.343 | 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 ); 
25-5-17 10:18:18.345 | 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 ); 
25-5-17 10:18:18.348 | 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 ); 
25-5-17 10:18:18.350 | 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 ); 
25-5-17 10:18:18.352 | 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 ); 
25-5-17 10:18:18.355 | 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 ); 
25-5-17 10:18:18.357 | 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) ); 
25-5-17 10:18:18.359 | 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) ); 
25-5-17 10:18:18.361 | 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) ); 
25-5-17 10:18:18.363 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:18:18.363 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:18:18.364 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:18:18.366 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:18:18.368 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:18:18.370 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:18:18.372 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:18:18.374 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:18:18.376 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:18:18.376 | 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'; 
25-5-17 10:18:18.380 | 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'; 
25-5-17 10:18:18.382 | 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; 
25-5-17 10:18:18.385 | 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'; 
25-5-17 10:18:18.387 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:18:18.387 | 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; 
25-5-17 10:18:18.390 | 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; 
25-5-17 10:18:18.392 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:18:18.392 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:18:18.392 | 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; 
25-5-17 10:18:18.394 | DownOperation   | Test worker    | INFO : 
25-5-17 10:18:18.394 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:18:18.394 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.394 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@5108d2ba) ...
25-5-17 10:18:18.394 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.395 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.395 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.395 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:18:18.395 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.395 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@36e7ec67) ...
25-5-17 10:18:18.395 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.395 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
25-5-17 10:18:18.395 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3bb0fe47) ...
25-5-17 10:18:18.395 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@aebc2bf) ...
25-5-17 10:18:18.395 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707498309] ...
25-5-17 10:18:18.395 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707498309]
25-5-17 10:18:18.396 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707498309] ...
25-5-17 10:18:18.396 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:18:18.396 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000001
25-5-17 10:18:18.396 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@407ea570) ...
25-5-17 10:18:18.396 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:18:18.397 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:18:18.398 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707498294
25-5-17 10:18:18.398 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.398 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:18:18.398 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1495707498294], B=[]}
25-5-17 10:18:18.398 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:18:18.398 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707498294
25-5-17 10:18:18.398 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:18:18.398 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707498294
25-5-17 10:18:18.398 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:18:18.398 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:18:18.398 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:18:18.398 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
25-5-17 10:18:18.398 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707498294]
25-5-17 10:18:18.398 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:18:18.398 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1495707498294]
25-5-17 10:18:18.398 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:18:18.398 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:18:18.399 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707498294
25-5-17 10:18:18.401 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:18:18.401 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.401 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:18:18.401 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:18:18.402 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
25-5-17 10:18:18.402 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.402 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A-original
25-5-17 10:18:18.402 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170525101612005-63448-client-B/A-original
25-5-17 10:18:18.402 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.402 | DownOperation   | Test worker    | INFO :   + Adding multichunk 4c8f75a00426ed280b1855da8e564bf1c6e4de19 to download list ...
25-5-17 10:18:18.402 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:18:18.402 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@1f9cca15) ...
25-5-17 10:18:18.402 | Downloader      | Test worker    | INFO :   + Downloading multichunk 4c8f75a00426ed280b1855da8e564bf1c6e4de19 ...
25-5-17 10:18:18.403 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 4c8f75a00426ed280b1855da8e564bf1c6e4de19 ...
25-5-17 10:18:18.403 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 4c8f75a00426ed280b1855da8e564bf1c6e4de19 ...
25-5-17 10:18:18.404 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:18:18.404 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.404 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:18:18.404 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.404 | Assembler       | Test worker    | INFO :      - Creating file A-original to /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/temp-reconstructedFileVersion-5944731328308571063.tmp ...
25-5-17 10:18:18.405 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
25-5-17 10:18:18.405 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:18:18.405 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
25-5-17 10:18:18.405 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1495707498294, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
25-5-17 10:18:18.413 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707498309] ...
25-5-17 10:18:18.413 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707498309]
25-5-17 10:18:18.413 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.413 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.413 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@aecc7a1) ...
25-5-17 10:18:18.413 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:18:18.416 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170525101612005-63448-client-A/A-original, but actual PATH = tmp/syncanytest/syncany-170525101612005-63448-client-B/A-original, for file tmp/syncanytest/syncany-170525101612005-63448-client-B/A-original
25-5-17 10:18:18.417 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.417 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.428 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
25-5-17 10:18:18.429 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
25-5-17 10:18:18.430 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
25-5-17 10:18:18.430 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
25-5-17 10:18:18.430 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
25-5-17 10:18:18.431 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.431 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.432 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
25-5-17 10:18:18.432 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
25-5-17 10:18:18.432 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.433 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.433 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.433 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.434 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.434 | UpOperation     | Test worker    | INFO : 
25-5-17 10:18:18.434 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
25-5-17 10:18:18.434 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.434 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2e7464e2) ...
25-5-17 10:18:18.434 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.434 | StatusOperation | Test worker    | INFO : 
25-5-17 10:18:18.434 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
25-5-17 10:18:18.434 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.434 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:18:18.434 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@45f4b705) ...
25-5-17 10:18:18.435 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101612005-63448-client-B ...
25-5-17 10:18:18.435 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:18:18.435 | StatusOperation | Test worker    | FINE : - New file: B-moved
25-5-17 10:18:18.435 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@c44409b) ...
25-5-17 10:18:18.435 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.435 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.435 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.435 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:18:18.435 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.435 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@71db8186) ...
25-5-17 10:18:18.436 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.436 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.436 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@599f4772) ...
25-5-17 10:18:18.436 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:18:18.436 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1495707498433] ...
25-5-17 10:18:18.436 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1495707498433]
25-5-17 10:18:18.436 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1495707498433] ...
25-5-17 10:18:18.436 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.437 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:18:18.437 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:18:18.437 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@e121a54) ...
25-5-17 10:18:18.437 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:18:18.438 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A-original, type=FILE, status=DELETED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.438 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.438 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.438 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.439 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c
25-5-17 10:18:18.439 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c > /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.439 | Indexer         | AsyncI/syncany | FINE : - /File: B-moved (checksum 286eab6a0bcabc8fb6b685a58bc380f9eda6330c)
25-5-17 10:18:18.440 | Indexer         | AsyncI/syncany | FINE :    * Found old file history a8f7bfbcd69bfae8baebdd87a6f738c8d8ef75bd (by checksum: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c), appending new version.
25-5-17 10:18:18.440 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-original, for file A-original
25-5-17 10:18:18.440 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.440 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.440 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@330c1d60) ...
25-5-17 10:18:18.440 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@4a9fa93a) ...
25-5-17 10:18:18.440 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498437, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.441 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@796a2c48) ...
25-5-17 10:18:18.441 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:18:18.441 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
25-5-17 10:18:18.441 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:18:18.442 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A1,B1)/T=1495707498441, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.442 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A1,B1)/T=1495707498441 to file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000001 ... 
25-5-17 10:18:18.442 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000001 ...
25-5-17 10:18:18.444 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:18:18.444 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000001 to RemoteFile[name=database-B-0000000001] ...
25-5-17 10:18:18.444 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000001 -> Temp. remote file: RemoteFile[name=temp-xvVBP-database-B-0000000001], final location: RemoteFile[name=database-B-0000000001]
25-5-17 10:18:18.444 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:18:18.444 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:18:18.445 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:18:18.445 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/temp-transaction-3155804052551732201.tmp
25-5-17 10:18:18.445 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@54d87741) ...
25-5-17 10:18:18.445 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-768e289c] ...
25-5-17 10:18:18.446 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:18:18.446 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1fd6e78a) ...
25-5-17 10:18:18.446 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000001 to temp. file RemoteFile[name=temp-xvVBP-database-B-0000000001] ...
25-5-17 10:18:18.446 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-xvVBP-database-B-0000000001] to final location RemoteFile[name=database-B-0000000001] ...
25-5-17 10:18:18.446 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-768e289c] ...
25-5-17 10:18:18.446 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:18:18.446 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:18:18.446 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A1,B1)/T=1495707498441) ...
25-5-17 10:18:18.446 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:18:18.450 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A1,B1)/T=1495707498441, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.451 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:18:18.451 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:18:18.451 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498445, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:18:18.451 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:18:18.453 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1495707498433] ...
25-5-17 10:18:18.453 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1495707498433]
25-5-17 10:18:18.453 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.453 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.453 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@36ce49e3) ...
25-5-17 10:18:18.453 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.454 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.454 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.454 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.455 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.455 | DownOperation   | Test worker    | INFO : 
25-5-17 10:18:18.455 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
25-5-17 10:18:18.455 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.455 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@2782ed82) ...
25-5-17 10:18:18.455 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.455 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.456 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.456 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:18:18.456 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.456 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@aa1efff) ...
25-5-17 10:18:18.456 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.456 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
25-5-17 10:18:18.456 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.456 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@125f3aeb) ...
25-5-17 10:18:18.456 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@7d60d68f) ...
25-5-17 10:18:18.456 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1495707498454] ...
25-5-17 10:18:18.456 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1495707498454]
25-5-17 10:18:18.456 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1495707498454] ...
25-5-17 10:18:18.457 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:18:18.457 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-B-0000000001
25-5-17 10:18:18.457 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@381c9d63) ...
25-5-17 10:18:18.457 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:18:18.457 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-B-0000000001 ...
25-5-17 10:18:18.458 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.458 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.458 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.458 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:18:18.459 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1495707498294], B=[B/(A1,B1)/T=1495707498441]}
25-5-17 10:18:18.459 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707498294
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707498294
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.459 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:18:18.459 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1495707498294]
25-5-17 10:18:18.459 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441]
25-5-17 10:18:18.459 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:18:18.459 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A1,B1)/T=1495707498441]
25-5-17 10:18:18.459 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:18:18.459 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-B-0000000001 ...
25-5-17 10:18:18.460 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.460 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:18:18.460 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.461 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:18:18.461 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:18:18.461 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.461 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.461 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-original, for file A-original
25-5-17 10:18:18.461 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-original, local version = FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.461 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.461 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:18:18.462 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:18:18.462 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.462 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:18:18.462 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.462 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-original to /tmp/syncanytest/syncany-170525101612005-63448-client-A/B-moved ...
25-5-17 10:18:18.462 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
25-5-17 10:18:18.462 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:18:18.462 | DownOperation   | Test worker    | INFO :   + Applying database version (A1,B1)
25-5-17 10:18:18.462 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A1,B1)/T=1495707498441, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.468 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1495707498454] ...
25-5-17 10:18:18.469 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1495707498454]
25-5-17 10:18:18.469 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.469 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.469 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@2233ed81) ...
25-5-17 10:18:18.469 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:18:18.471 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170525101612005-63448-client-A/B-moved, but actual PATH = tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved, for file tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.472 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.472 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.482 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
25-5-17 10:18:18.483 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
25-5-17 10:18:18.483 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
25-5-17 10:18:18.484 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
25-5-17 10:18:18.484 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
25-5-17 10:18:18.484 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.485 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.485 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
25-5-17 10:18:18.485 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
25-5-17 10:18:18.486 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.486 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.486 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.486 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.487 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.487 | UpOperation     | Test worker    | INFO : 
25-5-17 10:18:18.487 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:18:18.487 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.487 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2db6a73) ...
25-5-17 10:18:18.488 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.488 | StatusOperation | Test worker    | INFO : 
25-5-17 10:18:18.488 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:18:18.488 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.488 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:18:18.488 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3d76b594) ...
25-5-17 10:18:18.488 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101612005-63448-client-A ...
25-5-17 10:18:18.488 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:18:18.488 | StatusOperation | Test worker    | FINE : - New file: A-moved
25-5-17 10:18:18.488 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@3c669949) ...
25-5-17 10:18:18.488 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.489 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.489 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.489 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:18:18.489 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.489 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@66f2dda5) ...
25-5-17 10:18:18.489 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.489 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.489 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.489 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@12d561a3) ...
25-5-17 10:18:18.489 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:18:18.489 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707498486] ...
25-5-17 10:18:18.489 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707498486]
25-5-17 10:18:18.490 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707498486] ...
25-5-17 10:18:18.490 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.490 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:18:18.490 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:18:18.490 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@f08777f) ...
25-5-17 10:18:18.490 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:18:18.492 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=3, path=B-moved, type=FILE, status=DELETED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.492 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.492 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved
25-5-17 10:18:18.492 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved
25-5-17 10:18:18.493 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c
25-5-17 10:18:18.493 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c > /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved
25-5-17 10:18:18.493 | Indexer         | AsyncI/syncany | FINE : - /File: A-moved (checksum 286eab6a0bcabc8fb6b685a58bc380f9eda6330c)
25-5-17 10:18:18.494 | Indexer         | AsyncI/syncany | FINE :    * Found old file history a8f7bfbcd69bfae8baebdd87a6f738c8d8ef75bd (by checksum: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c), appending new version.
25-5-17 10:18:18.494 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
25-5-17 10:18:18.494 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.494 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.494 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@6d2334d7) ...
25-5-17 10:18:18.494 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@7336d738) ...
25-5-17 10:18:18.494 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498490, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.494 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@5acec160) ...
25-5-17 10:18:18.494 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:18:18.495 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1,B1)
25-5-17 10:18:18.495 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:18:18.495 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2,B1)/T=1495707498495, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.495 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2,B1)/T=1495707498495 to file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000002 ... 
25-5-17 10:18:18.495 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000002 ...
25-5-17 10:18:18.497 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:18:18.497 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
25-5-17 10:18:18.497 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-ynQCt-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
25-5-17 10:18:18.497 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:18:18.497 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:18:18.497 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:18:18.498 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/temp-transaction-3955804586426155463.tmp
25-5-17 10:18:18.498 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@491a2a3f) ...
25-5-17 10:18:18.498 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-326ef2e1] ...
25-5-17 10:18:18.498 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:18:18.498 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@314fb50d) ...
25-5-17 10:18:18.498 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-ynQCt-database-A-0000000002] ...
25-5-17 10:18:18.498 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-ynQCt-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
25-5-17 10:18:18.499 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-326ef2e1] ...
25-5-17 10:18:18.499 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:18:18.499 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:18:18.499 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2,B1)/T=1495707498495) ...
25-5-17 10:18:18.499 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:18:18.503 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2,B1)/T=1495707498495, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.503 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:18:18.503 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:18:18.503 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498497, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:18:18.503 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:18:18.505 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707498486] ...
25-5-17 10:18:18.505 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707498486]
25-5-17 10:18:18.505 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.506 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.506 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@48fd662a) ...
25-5-17 10:18:18.506 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.506 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.506 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.506 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.507 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.507 | DownOperation   | Test worker    | INFO : 
25-5-17 10:18:18.507 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:18:18.507 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.507 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@78632e1e) ...
25-5-17 10:18:18.507 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.509 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.509 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.509 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:18:18.509 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.509 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@52e5f648) ...
25-5-17 10:18:18.509 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.509 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
25-5-17 10:18:18.509 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.509 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.509 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@254fdfc4) ...
25-5-17 10:18:18.509 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@4f7f832) ...
25-5-17 10:18:18.509 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707498506] ...
25-5-17 10:18:18.509 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707498506]
25-5-17 10:18:18.510 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707498506] ...
25-5-17 10:18:18.510 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:18:18.510 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000002
25-5-17 10:18:18.510 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@ef239f0) ...
25-5-17 10:18:18.514 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:18:18.514 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000002 ...
25-5-17 10:18:18.515 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.515 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.515 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.515 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.515 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:18:18.515 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A2,B1)/T=1495707498495], B=[A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441]}
25-5-17 10:18:18.515 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:18:18.515 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707498294
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707498294
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.516 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:18:18.516 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441]
25-5-17 10:18:18.516 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495]
25-5-17 10:18:18.516 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:18:18.516 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A2,B1)/T=1495707498495]
25-5-17 10:18:18.516 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:18:18.516 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000002 ...
25-5-17 10:18:18.516 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.516 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:18:18.517 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.517 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:18:18.517 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:18:18.517 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.517 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.518 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
25-5-17 10:18:18.518 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved, local version = FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.518 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.518 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:18:18.518 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:18:18.518 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.518 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:18:18.518 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.519 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved to /tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved ...
25-5-17 10:18:18.519 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
25-5-17 10:18:18.519 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:18:18.519 | DownOperation   | Test worker    | INFO :   + Applying database version (A2,B1)
25-5-17 10:18:18.519 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2,B1)/T=1495707498495, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.525 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707498506] ...
25-5-17 10:18:18.526 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707498506]
25-5-17 10:18:18.526 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.526 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.526 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@83392ad) ...
25-5-17 10:18:18.526 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:18:18.529 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved, but actual PATH = tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved, for file tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved
25-5-17 10:18:18.529 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.530 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.540 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
25-5-17 10:18:18.540 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
25-5-17 10:18:18.541 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
25-5-17 10:18:18.541 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
25-5-17 10:18:18.542 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
25-5-17 10:18:18.542 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.543 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.543 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
25-5-17 10:18:18.544 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
25-5-17 10:18:18.544 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.544 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.544 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.544 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.554 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.554 | DownOperation   | Test worker    | INFO : 
25-5-17 10:18:18.554 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
25-5-17 10:18:18.554 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.554 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@18048363) ...
25-5-17 10:18:18.554 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.555 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.555 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.555 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:18:18.555 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.555 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@33421999) ...
25-5-17 10:18:18.555 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.555 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.556 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.556 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.556 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3d473c58) ...
25-5-17 10:18:18.556 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
25-5-17 10:18:18.556 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@74b4e510) ...
25-5-17 10:18:18.560 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved, but actual PATH = tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved, for file tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved
25-5-17 10:18:18.560 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.561 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.576 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
25-5-17 10:18:18.577 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
25-5-17 10:18:18.578 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
25-5-17 10:18:18.578 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
25-5-17 10:18:18.579 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
25-5-17 10:18:18.579 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.580 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.580 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
25-5-17 10:18:18.581 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
25-5-17 10:18:18.581 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.581 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.581 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.581 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.581 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.581 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.581 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.582 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.582 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.582 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.582 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.582 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.582 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.582 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.582 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.582 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.582 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.582 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.582 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.582 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.583 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.583 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.583 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.583 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.584 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.584 | UpOperation     | Test worker    | INFO : 
25-5-17 10:18:18.584 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:18:18.584 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.584 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2bee92f) ...
25-5-17 10:18:18.584 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.584 | StatusOperation | Test worker    | INFO : 
25-5-17 10:18:18.584 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:18:18.584 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.584 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:18:18.584 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@22d7f713) ...
25-5-17 10:18:18.585 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101612005-63448-client-A ...
25-5-17 10:18:18.585 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:18:18.585 | StatusOperation | Test worker    | FINE : - New file: A-moved-again
25-5-17 10:18:18.585 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@60eb9c4e) ...
25-5-17 10:18:18.585 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.586 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.586 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.586 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:18:18.586 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.586 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@e485ba1) ...
25-5-17 10:18:18.586 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.586 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.586 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.586 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.586 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7ccd522d) ...
25-5-17 10:18:18.586 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:18:18.586 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707498583] ...
25-5-17 10:18:18.586 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707498583]
25-5-17 10:18:18.586 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707498583] ...
25-5-17 10:18:18.587 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.587 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:18:18.587 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:18:18.587 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@2f7abeae) ...
25-5-17 10:18:18.587 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:18:18.588 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=4, path=A-moved, type=FILE, status=DELETED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.588 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.588 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved-again
25-5-17 10:18:18.588 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved-again
25-5-17 10:18:18.589 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c
25-5-17 10:18:18.589 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c > /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved-again
25-5-17 10:18:18.589 | Indexer         | AsyncI/syncany | FINE : - /File: A-moved-again (checksum 286eab6a0bcabc8fb6b685a58bc380f9eda6330c)
25-5-17 10:18:18.590 | Indexer         | AsyncI/syncany | FINE :    * Found old file history a8f7bfbcd69bfae8baebdd87a6f738c8d8ef75bd (by checksum: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c), appending new version.
25-5-17 10:18:18.590 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved-again, but actual PATH = A-moved, for file A-moved
25-5-17 10:18:18.590 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.590 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.590 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@2d766798) ...
25-5-17 10:18:18.590 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@66959031) ...
25-5-17 10:18:18.590 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498587, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.591 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:18:18.591 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2,B1)
25-5-17 10:18:18.591 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:18:18.591 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3,B1)/T=1495707498591, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.591 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3,B1)/T=1495707498591 to file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000003 ... 
25-5-17 10:18:18.591 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000003 ...
25-5-17 10:18:18.592 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:18:18.592 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
25-5-17 10:18:18.592 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-oXBqT-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
25-5-17 10:18:18.592 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:18:18.592 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:18:18.593 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/temp-transaction-7120240686641065645.tmp
25-5-17 10:18:18.593 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@e9fc1a5) ...
25-5-17 10:18:18.593 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-6f6ee759] ...
25-5-17 10:18:18.593 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:18:18.593 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1130544f) ...
25-5-17 10:18:18.593 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-oXBqT-database-A-0000000003] ...
25-5-17 10:18:18.594 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-oXBqT-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
25-5-17 10:18:18.594 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-6f6ee759] ...
25-5-17 10:18:18.594 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:18:18.594 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:18:18.594 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3,B1)/T=1495707498591) ...
25-5-17 10:18:18.594 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:18:18.596 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@6fd8d56e) ...
25-5-17 10:18:18.599 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3,B1)/T=1495707498591, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.599 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:18:18.599 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:18:18.601 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:18:18.601 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498601, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:18:18.601 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:18:18.604 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707498583] ...
25-5-17 10:18:18.605 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707498583]
25-5-17 10:18:18.605 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.605 | Cache           | Test worker    | INFO : Cache size okay (53 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.605 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@70c976a9) ...
25-5-17 10:18:18.605 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.605 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.605 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.605 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.605 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.605 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.605 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.605 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.605 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.605 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.605 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.605 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.606 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.606 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.606 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.606 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.606 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.606 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.606 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.606 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.606 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.606 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.606 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.606 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.607 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.607 | DownOperation   | Test worker    | INFO : 
25-5-17 10:18:18.607 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:18:18.607 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.607 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@4750ceee) ...
25-5-17 10:18:18.607 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.607 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.607 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.607 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:18:18.607 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.607 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@43bab646) ...
25-5-17 10:18:18.607 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.607 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.608 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
25-5-17 10:18:18.608 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.608 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.608 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1beea9ac) ...
25-5-17 10:18:18.608 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@c5a1294) ...
25-5-17 10:18:18.608 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707498606] ...
25-5-17 10:18:18.608 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707498606]
25-5-17 10:18:18.608 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707498606] ...
25-5-17 10:18:18.608 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:18:18.608 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000003
25-5-17 10:18:18.608 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@6f47f2ad) ...
25-5-17 10:18:18.609 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:18:18.609 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000003 ...
25-5-17 10:18:18.610 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.610 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.610 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.610 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.610 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.611 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:18:18.611 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A3,B1)/T=1495707498591], B=[A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495]}
25-5-17 10:18:18.611 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707498294
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707498294
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO :   + A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.611 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:18:18.611 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495]
25-5-17 10:18:18.611 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495, A/(A3,B1)/T=1495707498591]
25-5-17 10:18:18.611 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:18:18.611 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A3,B1)/T=1495707498591]
25-5-17 10:18:18.611 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:18:18.611 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000003 ...
25-5-17 10:18:18.612 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.612 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:18:18.613 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.613 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:18:18.613 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:18:18.613 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.613 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.614 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved-again, but actual PATH = A-moved, for file A-moved
25-5-17 10:18:18.614 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved, local version = FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.614 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.614 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:18:18.614 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:18:18.614 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.614 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:18:18.614 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.615 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved to /tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved-again ...
25-5-17 10:18:18.615 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
25-5-17 10:18:18.615 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:18:18.615 | DownOperation   | Test worker    | INFO :   + Applying database version (A3,B1)
25-5-17 10:18:18.615 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3,B1)/T=1495707498591, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.621 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707498606] ...
25-5-17 10:18:18.621 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707498606]
25-5-17 10:18:18.622 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.622 | Cache           | Test worker    | INFO : Cache size okay (53 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.622 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@4bf0265d) ...
25-5-17 10:18:18.622 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:18:18.626 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved-again, but actual PATH = tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved-again, for file tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved-again
25-5-17 10:18:18.626 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.627 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.641 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
25-5-17 10:18:18.642 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
25-5-17 10:18:18.643 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
25-5-17 10:18:18.643 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
25-5-17 10:18:18.644 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
25-5-17 10:18:18.644 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.644 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.645 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
25-5-17 10:18:18.645 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
25-5-17 10:18:18.646 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.646 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.646 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.646 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.647 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.647 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.650 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.650 | UpOperation     | Test worker    | INFO : 
25-5-17 10:18:18.650 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
25-5-17 10:18:18.650 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.650 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@1294520e) ...
25-5-17 10:18:18.650 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.650 | StatusOperation | Test worker    | INFO : 
25-5-17 10:18:18.650 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
25-5-17 10:18:18.650 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.650 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:18:18.651 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@1ed4f542) ...
25-5-17 10:18:18.651 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101612005-63448-client-B ...
25-5-17 10:18:18.651 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:18:18.651 | StatusOperation | Test worker    | FINE : - New file: B-moved
25-5-17 10:18:18.651 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@635363ad) ...
25-5-17 10:18:18.652 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.652 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.652 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@3dfe9cfa) ...
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.652 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.652 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@734dfd5d) ...
25-5-17 10:18:18.652 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:18:18.652 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1495707498647] ...
25-5-17 10:18:18.652 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1495707498647]
25-5-17 10:18:18.653 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1495707498647] ...
25-5-17 10:18:18.653 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.654 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:18:18.654 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:18:18.654 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@57fee26c) ...
25-5-17 10:18:18.654 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:18:18.655 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=5, path=A-moved-again, type=FILE, status=DELETED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.655 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.655 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.655 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.656 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c
25-5-17 10:18:18.656 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c > /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.656 | Indexer         | AsyncI/syncany | FINE : - /File: B-moved (checksum 286eab6a0bcabc8fb6b685a58bc380f9eda6330c)
25-5-17 10:18:18.657 | Indexer         | AsyncI/syncany | FINE :    * Found old file history a8f7bfbcd69bfae8baebdd87a6f738c8d8ef75bd (by checksum: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c), appending new version.
25-5-17 10:18:18.657 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-moved-again, for file A-moved-again
25-5-17 10:18:18.657 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.657 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.657 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@3b3c0a3a) ...
25-5-17 10:18:18.657 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@2b20b395) ...
25-5-17 10:18:18.657 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498654, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.658 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:18:18.658 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3,B1)
25-5-17 10:18:18.658 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:18:18.658 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A3,B2)/T=1495707498658, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.658 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A3,B2)/T=1495707498658 to file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000002 ... 
25-5-17 10:18:18.658 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000002 ...
25-5-17 10:18:18.659 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:18:18.659 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000002 to RemoteFile[name=database-B-0000000002] ...
25-5-17 10:18:18.659 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000002 -> Temp. remote file: RemoteFile[name=temp-QtFog-database-B-0000000002], final location: RemoteFile[name=database-B-0000000002]
25-5-17 10:18:18.659 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:18:18.659 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:18:18.660 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/temp-transaction-5409613140791021607.tmp
25-5-17 10:18:18.660 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@22a42493) ...
25-5-17 10:18:18.660 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-30c9d021] ...
25-5-17 10:18:18.661 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:18:18.661 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6443d69e) ...
25-5-17 10:18:18.661 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-B-0000000002 to temp. file RemoteFile[name=temp-QtFog-database-B-0000000002] ...
25-5-17 10:18:18.661 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-QtFog-database-B-0000000002] to final location RemoteFile[name=database-B-0000000002] ...
25-5-17 10:18:18.661 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-30c9d021] ...
25-5-17 10:18:18.661 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:18:18.661 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:18:18.661 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A3,B2)/T=1495707498658) ...
25-5-17 10:18:18.662 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:18:18.663 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@6947cb49) ...
25-5-17 10:18:18.666 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A3,B2)/T=1495707498658, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.666 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:18:18.666 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:18:18.669 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:18:18.669 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498669, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:18:18.669 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:18:18.672 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1495707498647] ...
25-5-17 10:18:18.672 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1495707498647]
25-5-17 10:18:18.672 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.672 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.673 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@4035788a) ...
25-5-17 10:18:18.673 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.673 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.674 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.674 | DownOperation   | Test worker    | INFO : 
25-5-17 10:18:18.674 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
25-5-17 10:18:18.674 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.674 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@41dc936) ...
25-5-17 10:18:18.674 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.675 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.675 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@68af7c6) ...
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000002 is new.
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.675 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.675 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3616ebae) ...
25-5-17 10:18:18.675 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@5a747039) ...
25-5-17 10:18:18.675 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1495707498673] ...
25-5-17 10:18:18.675 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1495707498673]
25-5-17 10:18:18.676 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1495707498673] ...
25-5-17 10:18:18.676 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:18:18.676 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000002 to local cache at /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-B-0000000002
25-5-17 10:18:18.676 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@1082e501) ...
25-5-17 10:18:18.676 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:18:18.677 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-B-0000000002 ...
25-5-17 10:18:18.678 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A3,B2)/T=1495707498658
25-5-17 10:18:18.678 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-B-0000000002; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.679 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.679 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.679 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.679 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.679 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:18:18.679 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495, A/(A3,B1)/T=1495707498591], B=[B/(A3,B2)/T=1495707498658]}
25-5-17 10:18:18.679 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707498294
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A3,B2)/T=1495707498658
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707498294
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO :   + A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO :   + B/(A3,B2)/T=1495707498658
25-5-17 10:18:18.679 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:18:18.679 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495, A/(A3,B1)/T=1495707498591]
25-5-17 10:18:18.679 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495, A/(A3,B1)/T=1495707498591, B/(A3,B2)/T=1495707498658]
25-5-17 10:18:18.679 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:18:18.679 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A3,B2)/T=1495707498658]
25-5-17 10:18:18.679 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:18:18.679 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-B-0000000002 ...
25-5-17 10:18:18.681 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A3,B2)/T=1495707498658
25-5-17 10:18:18.681 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:18:18.681 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.682 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:18:18.682 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:18:18.682 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.682 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.683 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-moved-again, for file A-moved-again
25-5-17 10:18:18.683 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved-again, local version = FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.683 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.683 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:18:18.683 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:18:18.683 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.683 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:18:18.683 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.683 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved-again to /tmp/syncanytest/syncany-170525101612005-63448-client-A/B-moved ...
25-5-17 10:18:18.684 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
25-5-17 10:18:18.684 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:18:18.684 | DownOperation   | Test worker    | INFO :   + Applying database version (A3,B2)
25-5-17 10:18:18.684 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A3,B2)/T=1495707498658, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.692 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1495707498673] ...
25-5-17 10:18:18.692 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1495707498673]
25-5-17 10:18:18.693 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.693 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.693 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@b152c01) ...
25-5-17 10:18:18.693 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:18:18.697 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170525101612005-63448-client-A/B-moved, but actual PATH = tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved, for file tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved
25-5-17 10:18:18.698 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.698 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.713 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
25-5-17 10:18:18.714 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
25-5-17 10:18:18.714 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
25-5-17 10:18:18.715 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
25-5-17 10:18:18.718 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
25-5-17 10:18:18.718 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.719 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.719 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
25-5-17 10:18:18.720 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
25-5-17 10:18:18.720 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.720 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.721 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.721 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.721 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.721 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.721 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.721 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.721 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.721 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.721 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.721 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-A' ...
25-5-17 10:18:18.722 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.722 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.722 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.722 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.722 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.722 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.722 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.722 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.722 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.722 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.722 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.723 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.723 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.723 | UpOperation     | Test worker    | INFO : 
25-5-17 10:18:18.723 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:18:18.723 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.723 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@67ca8443) ...
25-5-17 10:18:18.724 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.724 | StatusOperation | Test worker    | INFO : 
25-5-17 10:18:18.724 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:18:18.724 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.724 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:18:18.724 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@2cb104bd) ...
25-5-17 10:18:18.724 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101612005-63448-client-A ...
25-5-17 10:18:18.725 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:18:18.725 | StatusOperation | Test worker    | FINE : - New file: A-moved
25-5-17 10:18:18.725 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@5e0911c4) ...
25-5-17 10:18:18.725 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.725 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.725 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.725 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:18:18.725 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.725 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7a9bdd00) ...
25-5-17 10:18:18.725 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.725 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.726 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
25-5-17 10:18:18.726 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.726 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.726 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.726 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@38a2f16) ...
25-5-17 10:18:18.726 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:18:18.726 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707498723] ...
25-5-17 10:18:18.726 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707498723]
25-5-17 10:18:18.726 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707498723] ...
25-5-17 10:18:18.726 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.727 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:18:18.727 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:18:18.727 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@454e23ec) ...
25-5-17 10:18:18.727 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:18:18.728 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=6, path=B-moved, type=FILE, status=DELETED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.728 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.728 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved
25-5-17 10:18:18.728 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved
25-5-17 10:18:18.729 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c
25-5-17 10:18:18.730 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c > /tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved
25-5-17 10:18:18.730 | Indexer         | AsyncI/syncany | FINE : - /File: A-moved (checksum 286eab6a0bcabc8fb6b685a58bc380f9eda6330c)
25-5-17 10:18:18.731 | Indexer         | AsyncI/syncany | FINE :    * Found old file history a8f7bfbcd69bfae8baebdd87a6f738c8d8ef75bd (by checksum: 286eab6a0bcabc8fb6b685a58bc380f9eda6330c), appending new version.
25-5-17 10:18:18.731 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
25-5-17 10:18:18.731 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.731 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.731 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@3200fe35) ...
25-5-17 10:18:18.731 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@29b30614) ...
25-5-17 10:18:18.731 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498727, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.732 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:18:18.732 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3,B2)
25-5-17 10:18:18.732 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:18:18.732 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A4,B2)/T=1495707498732, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.732 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A4,B2)/T=1495707498732 to file /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000004 ... 
25-5-17 10:18:18.732 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000004 ...
25-5-17 10:18:18.733 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:18:18.733 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000004 to RemoteFile[name=database-A-0000000004] ...
25-5-17 10:18:18.733 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-JQqOW-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
25-5-17 10:18:18.733 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:18:18.733 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@3499ad16) ...
25-5-17 10:18:18.733 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:18:18.734 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/temp-transaction-3055366712553473636.tmp
25-5-17 10:18:18.734 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@7c74ee2b) ...
25-5-17 10:18:18.734 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-2c12af13] ...
25-5-17 10:18:18.734 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:18:18.734 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@716eb382) ...
25-5-17 10:18:18.734 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101612005-63448-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-JQqOW-database-A-0000000004] ...
25-5-17 10:18:18.735 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-JQqOW-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
25-5-17 10:18:18.735 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-2c12af13] ...
25-5-17 10:18:18.735 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:18:18.735 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:18:18.735 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A4,B2)/T=1495707498732) ...
25-5-17 10:18:18.736 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:18:18.739 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:18:18.741 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A4,B2)/T=1495707498732, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.741 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:18:18.741 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:18:18.741 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707498739, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:18:18.741 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:18:18.743 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707498723] ...
25-5-17 10:18:18.745 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707498723]
25-5-17 10:18:18.745 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.746 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.746 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@2deee22f) ...
25-5-17 10:18:18.746 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.746 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101612005-63448-client-B' ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:18:18.746 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:18:18.746 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:18:18.747 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.747 | DownOperation   | Test worker    | INFO : 
25-5-17 10:18:18.747 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:18:18.747 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.747 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@5fe78416) ...
25-5-17 10:18:18.747 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:18:18.748 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:18:18.748 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@689bd773) ...
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000002 is already known (in local database). Ignoring.
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.748 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:18:18.748 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4835ed91) ...
25-5-17 10:18:18.748 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@f6842ba) ...
25-5-17 10:18:18.748 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707498746] ...
25-5-17 10:18:18.748 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707498746]
25-5-17 10:18:18.748 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707498746] ...
25-5-17 10:18:18.749 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:18:18.749 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000004
25-5-17 10:18:18.749 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@7dacc820) ...
25-5-17 10:18:18.749 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:18:18.749 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000004 ...
25-5-17 10:18:18.751 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4,B2)/T=1495707498732
25-5-17 10:18:18.751 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-B-0000000002; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.751 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.751 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.751 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.752 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.752 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101612005-63448-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
25-5-17 10:18:18.752 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:18:18.752 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A4,B2)/T=1495707498732], B=[A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495, A/(A3,B1)/T=1495707498591, B/(A3,B2)/T=1495707498658]}
25-5-17 10:18:18.752 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:18:18.752 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707498294
25-5-17 10:18:18.752 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A3,B2)/T=1495707498658
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4,B2)/T=1495707498732
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707498294
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1495707498441
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1495707498495
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO :   + A/(A3,B1)/T=1495707498591
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO :   + B/(A3,B2)/T=1495707498658
25-5-17 10:18:18.753 | DatabaseReconci | Test worker    | INFO :   + A/(A4,B2)/T=1495707498732
25-5-17 10:18:18.753 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:18:18.754 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:18:18.754 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:18:18.754 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495, A/(A3,B1)/T=1495707498591, B/(A3,B2)/T=1495707498658]
25-5-17 10:18:18.754 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707498294, B/(A1,B1)/T=1495707498441, A/(A2,B1)/T=1495707498495, A/(A3,B1)/T=1495707498591, B/(A3,B2)/T=1495707498658, A/(A4,B2)/T=1495707498732]
25-5-17 10:18:18.754 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:18:18.754 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A4,B2)/T=1495707498732]
25-5-17 10:18:18.754 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:18:18.754 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101612005-63448-client-B/.syncany/cache/database-A-0000000004 ...
25-5-17 10:18:18.755 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4,B2)/T=1495707498732
25-5-17 10:18:18.755 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:18:18.756 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.757 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:18:18.757 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:18:18.757 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.757 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.758 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
25-5-17 10:18:18.758 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved, local version = FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:18:18.758 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.758 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:18:18.758 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:18:18.758 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.758 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:18:18.758 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Thu May 25 10:18:18 UTC 2017, linkTarget=null, checksum=286eab6a0bcabc8fb6b685a58bc380f9eda6330c, updated=Thu May 25 10:18:18 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:18:18.759 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-170525101612005-63448-client-B/B-moved to /tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved ...
25-5-17 10:18:18.759 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
25-5-17 10:18:18.760 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:18:18.760 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B2)
25-5-17 10:18:18.760 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4,B2)/T=1495707498732, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:18:18.766 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707498746] ...
25-5-17 10:18:18.767 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707498746]
25-5-17 10:18:18.767 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:18:18.767 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
25-5-17 10:18:18.767 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@78c6c33e) ...
25-5-17 10:18:18.767 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:18:18.772 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170525101612005-63448-client-A/A-moved, but actual PATH = tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved, for file tmp/syncanytest/syncany-170525101612005-63448-client-B/A-moved
25-5-17 10:18:18.772 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.773 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:18:18.787 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
25-5-17 10:18:18.788 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
25-5-17 10:18:18.788 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
25-5-17 10:18:18.788 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
25-5-17 10:18:18.789 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
25-5-17 10:18:18.789 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.790 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
25-5-17 10:18:18.790 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
25-5-17 10:18:18.790 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc