Class org.syncany.tests.integration.scenarios.Issue143ScenarioTest

1

tests

0

failures

0

ignored

2.822s

duration

100%

successful

Tests

Test Duration Result
testChangeAttributes 2.822s passed

Standard error

18-11-18 14:33:51.194 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.194 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
18-11-18 14:33:51.218 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
18-11-18 14:33:51.218 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
18-11-18 14:33:51.225 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
18-11-18 14:33:51.227 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
18-11-18 14:33:51.228 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
18-11-18 14:33:51.232 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
18-11-18 14:33:51.232 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
18-11-18 14:33:51.233 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
18-11-18 14:33:51.233 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
18-11-18 14:33:51.236 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.238 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.240 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.242 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.244 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.246 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.247 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.249 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:51.251 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
18-11-18 14:33:51.252 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
18-11-18 14:33:51.254 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
18-11-18 14:33:51.256 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
18-11-18 14:33:51.256 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
18-11-18 14:33:51.257 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
18-11-18 14:33:51.259 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
18-11-18 14:33:51.261 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
18-11-18 14:33:51.262 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
18-11-18 14:33:51.264 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
18-11-18 14:33:51.266 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
18-11-18 14:33:51.267 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
18-11-18 14:33:51.267 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
18-11-18 14:33:51.269 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
18-11-18 14:33:51.271 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
18-11-18 14:33:51.273 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
18-11-18 14:33:51.275 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
18-11-18 14:33:51.275 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
18-11-18 14:33:51.277 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
18-11-18 14:33:51.278 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
18-11-18 14:33:51.279 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
18-11-18 14:33:51.279 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
18-11-18 14:33:51.283 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.283 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:51.283 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.283 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.284 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.284 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.284 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:51.284 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:51.291 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.291 | UpOperation     | Test worker    | INFO : 
18-11-18 14:33:51.291 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:33:51.291 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.291 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@339425bb) ...
18-11-18 14:33:51.291 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.291 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:51.291 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:51.291 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.291 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:33:51.291 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:51.291 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@364dbf31) ...
18-11-18 14:33:51.292 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:51.292 | StatusOperation | Test worker    | FINE : - New file: file1.jpg
18-11-18 14:33:51.292 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:51.292 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@16a240b) ...
18-11-18 14:33:51.292 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:51.293 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.293 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:51.293 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:51.293 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.293 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@4035bc7d) ...
18-11-18 14:33:51.293 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:51.293 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@395a0572) ...
18-11-18 14:33:51.293 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:33:51.293 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551631284] ...
18-11-18 14:33:51.293 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551631284]
18-11-18 14:33:51.293 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551631284] ...
18-11-18 14:33:51.294 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.296 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:33:51.296 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:33:51.296 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@6b643d44) ...
18-11-18 14:33:51.296 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:33:51.296 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1.jpg
18-11-18 14:33:51.296 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1.jpg
18-11-18 14:33:51.301 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 9bb08a6f701dc04ea148a89d424389462d373c92
18-11-18 14:33:51.302 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk f64956361c96c84f9a06e68853bc7070a112cd33
18-11-18 14:33:51.302 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 9bb08a6f701dc04ea148a89d424389462d373c92 > f64956361c96c84f9a06e68853bc7070a112cd33
18-11-18 14:33:51.302 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 9bb08a6f701dc04ea148a89d424389462d373c92 > /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1.jpg
18-11-18 14:33:51.302 | Indexer         | AsyncI/syncany | FINE : - /File: file1.jpg (checksum 9bb08a6f701dc04ea148a89d424389462d373c92)
18-11-18 14:33:51.303 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: file1.jpg, checksum: 9bb08a6f701dc04ea148a89d424389462d373c92)
18-11-18 14:33:51.303 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file file1.jpg
18-11-18 14:33:51.303 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=file1.jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:51 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:51.303 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
18-11-18 14:33:51.303 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@137c6174) ...
18-11-18 14:33:51.303 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk f64956361c96c84f9a06e68853bc7070a112cd33
18-11-18 14:33:51.303 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@77ab9bfb) ...
18-11-18 14:33:51.303 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551631296, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:33:51.304 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:33:51.304 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
18-11-18 14:33:51.304 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:33:51.304 | UpOperation     | Test worker    | INFO : - Uploading multichunk f64956361c96c84f9a06e68853bc7070a112cd33 from /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/multichunk-f64956361c96c84f9a06e68853bc7070a112cd33 to RemoteFile[name=multichunk-f64956361c96c84f9a06e68853bc7070a112cd33] ...
18-11-18 14:33:51.304 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/multichunk-f64956361c96c84f9a06e68853bc7070a112cd33 -> Temp. remote file: RemoteFile[name=temp-doaeF-multichunk-f64956361c96c84f9a06e68853bc7070a112cd33], final location: RemoteFile[name=multichunk-f64956361c96c84f9a06e68853bc7070a112cd33]
18-11-18 14:33:51.304 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1542551631304, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:33:51.304 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1542551631304 to file /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000001 ... 
18-11-18 14:33:51.304 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000001 ...
18-11-18 14:33:51.305 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:33:51.305 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
18-11-18 14:33:51.305 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-ODWfB-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
18-11-18 14:33:51.305 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:33:51.305 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:33:51.306 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-transaction-4445476746151422762.tmp
18-11-18 14:33:51.306 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@1a770a56) ...
18-11-18 14:33:51.306 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-3e421bae] ...
18-11-18 14:33:51.307 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:33:51.307 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@32ac2811) ...
18-11-18 14:33:51.307 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/multichunk-f64956361c96c84f9a06e68853bc7070a112cd33 to temp. file RemoteFile[name=temp-doaeF-multichunk-f64956361c96c84f9a06e68853bc7070a112cd33] ...
18-11-18 14:33:51.307 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@17cf1750) ...
18-11-18 14:33:51.307 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-ODWfB-database-A-0000000001] ...
18-11-18 14:33:51.307 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-doaeF-multichunk-f64956361c96c84f9a06e68853bc7070a112cd33] to final location RemoteFile[name=multichunk-f64956361c96c84f9a06e68853bc7070a112cd33] ...
18-11-18 14:33:51.308 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-ODWfB-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
18-11-18 14:33:51.308 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-3e421bae] ...
18-11-18 14:33:51.308 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:33:51.308 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:33:51.308 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1542551631304) ...
18-11-18 14:33:51.309 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:33:51.310 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@2826e1ac) ...
18-11-18 14:33:51.314 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1542551631304, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:33:51.314 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:33:51.314 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:33:51.316 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:33:51.316 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551631316, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:33:51.316 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:33:51.318 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551631284] ...
18-11-18 14:33:51.322 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551631284]
18-11-18 14:33:51.322 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:51.323 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:51.323 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@16ec0f88) ...
18-11-18 14:33:51.323 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.323 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.323 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.323 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.323 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.323 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.323 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.323 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.323 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.324 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.324 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.324 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.324 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.324 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.324 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:51.324 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:51.324 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.324 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.324 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.324 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.324 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.324 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.324 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:51.324 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:51.333 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.333 | UpOperation     | Test worker    | INFO : 
18-11-18 14:33:51.333 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:33:51.333 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.333 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@7c8f868a) ...
18-11-18 14:33:51.333 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.333 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:51.333 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:51.333 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.333 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:33:51.333 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:51.333 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@77104f00) ...
18-11-18 14:33:51.334 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:51.335 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:51.335 | StatusOperation | Test worker    | FINE : - New file: file1 (copy).jpg
18-11-18 14:33:51.335 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@3d42e0d2) ...
18-11-18 14:33:51.335 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:51.336 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.336 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:51.336 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:51.336 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.336 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@49307a9c) ...
18-11-18 14:33:51.336 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:51.336 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:33:51.336 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1601bfd8) ...
18-11-18 14:33:51.336 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:33:51.336 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551631324] ...
18-11-18 14:33:51.336 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551631324]
18-11-18 14:33:51.337 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551631324] ...
18-11-18 14:33:51.337 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.342 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:33:51.342 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:33:51.343 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@2e36ef21) ...
18-11-18 14:33:51.343 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:33:51.343 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1 (copy).jpg
18-11-18 14:33:51.343 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1 (copy).jpg
18-11-18 14:33:51.344 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 9bb08a6f701dc04ea148a89d424389462d373c92
18-11-18 14:33:51.344 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 9bb08a6f701dc04ea148a89d424389462d373c92 > /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1 (copy).jpg
18-11-18 14:33:51.345 | Indexer         | AsyncI/syncany | FINE : - /File: file1 (copy).jpg (checksum 9bb08a6f701dc04ea148a89d424389462d373c92)
18-11-18 14:33:51.353 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: file1 (copy).jpg, checksum: 9bb08a6f701dc04ea148a89d424389462d373c92)
18-11-18 14:33:51.353 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file file1 (copy).jpg
18-11-18 14:33:51.353 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:51 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:51.353 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
18-11-18 14:33:51.353 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@1b5f9ac0) ...
18-11-18 14:33:51.353 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@19eabc41) ...
18-11-18 14:33:51.354 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551631343, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:51.354 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@3bd2a32b) ...
18-11-18 14:33:51.354 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:33:51.354 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
18-11-18 14:33:51.354 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:33:51.354 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1542551631354, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:51.354 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1542551631354 to file /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000002 ... 
18-11-18 14:33:51.354 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000002 ...
18-11-18 14:33:51.355 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:33:51.355 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
18-11-18 14:33:51.355 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-dwQUr-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
18-11-18 14:33:51.355 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:33:51.355 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:33:51.357 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:33:51.358 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-transaction-9099866917115539758.tmp
18-11-18 14:33:51.358 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@49e3f306) ...
18-11-18 14:33:51.358 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-e24f297] ...
18-11-18 14:33:51.358 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:33:51.359 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1512e5ef) ...
18-11-18 14:33:51.359 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-dwQUr-database-A-0000000002] ...
18-11-18 14:33:51.359 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-dwQUr-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
18-11-18 14:33:51.359 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-e24f297] ...
18-11-18 14:33:51.359 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:33:51.359 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:33:51.359 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1542551631354) ...
18-11-18 14:33:51.360 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:33:51.366 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1542551631354, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:51.366 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:33:51.366 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:33:51.366 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551631357, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:33:51.366 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:33:51.368 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551631324] ...
18-11-18 14:33:51.372 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551631324]
18-11-18 14:33:51.372 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:51.372 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:51.372 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@43a902b9) ...
18-11-18 14:33:51.373 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.373 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.373 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:51.373 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:51.379 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.379 | UpOperation     | Test worker    | INFO : 
18-11-18 14:33:51.379 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:33:51.379 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.379 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2cf4e248) ...
18-11-18 14:33:51.379 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.380 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:51.380 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:51.380 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.380 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:33:51.380 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:51.380 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@22f066a8) ...
18-11-18 14:33:51.380 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:51.381 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:51.381 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@35812001) ...
18-11-18 14:33:51.381 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:51.382 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.382 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:51.382 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:51.382 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.382 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@44963da5) ...
18-11-18 14:33:51.382 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:51.382 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:33:51.382 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:33:51.382 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@23850684) ...
18-11-18 14:33:51.382 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:33:51.382 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551631373] ...
18-11-18 14:33:51.382 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551631373]
18-11-18 14:33:51.382 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551631373] ...
18-11-18 14:33:51.383 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.385 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:33:51.385 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:33:51.385 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:33:51.386 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=file1 (copy).jpg, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:51 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:51.386 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:51 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:51.386 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1542551631385, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:51.387 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:33:51.387 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
18-11-18 14:33:51.387 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:33:51.387 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1542551631387, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:51.387 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1542551631387 to file /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000003 ... 
18-11-18 14:33:51.387 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000003 ...
18-11-18 14:33:51.388 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:33:51.388 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
18-11-18 14:33:51.388 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-HkZET-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
18-11-18 14:33:51.388 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:33:51.388 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:33:51.389 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-transaction-3831619587838666436.tmp
18-11-18 14:33:51.389 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@230c6192) ...
18-11-18 14:33:51.389 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-5217d5bd] ...
18-11-18 14:33:51.389 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:33:51.389 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@7f071ad4) ...
18-11-18 14:33:51.389 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-HkZET-database-A-0000000003] ...
18-11-18 14:33:51.390 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-HkZET-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
18-11-18 14:33:51.390 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-5217d5bd] ...
18-11-18 14:33:51.390 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:33:51.390 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:33:51.390 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1542551631387) ...
18-11-18 14:33:51.390 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:33:51.394 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1542551631387, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:51.394 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:33:51.394 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:33:51.396 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:33:51.397 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551631396, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:33:51.397 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:33:51.398 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551631373] ...
18-11-18 14:33:51.403 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551631373]
18-11-18 14:33:51.403 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:51.403 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:51.403 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@ddb1072) ...
18-11-18 14:33:51.403 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.403 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.403 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.403 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.403 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.403 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.403 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.403 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.403 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.404 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.404 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.404 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.404 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:51.404 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:51.404 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:51.404 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:51.404 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.404 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.404 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.404 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.404 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:51.404 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:51.404 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:51.404 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:51.408 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.408 | CleanupOperatio | Test worker    | INFO : 
18-11-18 14:33:51.408 | CleanupOperatio | Test worker    | INFO : Running 'Cleanup' at client A ...
18-11-18 14:33:51.408 | CleanupOperatio | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.409 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = (not set)
18-11-18 14:33:51.409 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.409 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:51.409 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:51.409 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.409 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:51.409 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@7e201e26) ...
18-11-18 14:33:51.409 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:51.410 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:51.410 | StatusOperation | Test worker    | INFO : - No changes to local database
18-11-18 14:33:51.410 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@7ca707d0) ...
18-11-18 14:33:51.410 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:51.410 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:51.410 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:51.410 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:51.410 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7396ce46) ...
18-11-18 14:33:51.410 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:51.410 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:51.410 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:51.410 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:51.410 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:51.411 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:51.411 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:51.411 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:51.411 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:51.411 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:33:51.411 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:33:51.411 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:33:51.411 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@6a0cbc8b) ...
18-11-18 14:33:51.411 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:51.411 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartSyncExternalEvent@5e62a802) ...
18-11-18 14:33:51.411 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartCleaningSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartCleaningSyncExternalEvent@1bc3a976) ...
18-11-18 14:33:51.411 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-cleanup-A-1542551631404] ...
18-11-18 14:33:51.411 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-cleanup-A-1542551631404]
18-11-18 14:33:51.412 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-cleanup-A-1542551631404] ...
18-11-18 14:33:51.412 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:33:51.412 | CleanupOperatio | Test worker    | INFO : Cleanup: Waiting a while to be sure that no other actions are running ...
18-11-18 14:33:52.612 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = (not set)
18-11-18 14:33:52.613 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.613 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:52.613 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:52.613 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.613 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:52.613 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@7a89dd49) ...
18-11-18 14:33:52.613 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:52.614 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:52.614 | StatusOperation | Test worker    | INFO : - No changes to local database
18-11-18 14:33:52.614 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@766ccd81) ...
18-11-18 14:33:52.614 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.614 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:52.614 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:52.614 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.614 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@439004d) ...
18-11-18 14:33:52.614 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.614 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.615 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:52.615 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.615 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.615 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.615 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.615 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:52.615 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:52.615 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:33:52.615 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:33:52.615 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:33:52.615 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@6abde279) ...
18-11-18 14:33:52.615 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:52.615 | CleanupOperatio | Test worker    | INFO : Cleanup: Starting transaction.
18-11-18 14:33:52.616 | CleanupOperatio | Test worker    | INFO : - Old version removal: Found 1 file histories and 1 file versions that need cleaning.
18-11-18 14:33:52.617 | CleanupOperatio | Test worker    | INFO : - Deleting remote multichunks ...
18-11-18 14:33:52.617 | CleanupOperatio | Test worker    | INFO : - Merge remote files ...
18-11-18 14:33:52.617 | CleanupOperatio | Test worker    | INFO : Databases: [RemoteFile[name=database-A-0000000001], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003]]
18-11-18 14:33:52.617 | CleanupOperatio | Test worker    | INFO :    + Writing new merge file (all files up to 3) to /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000004 ...
18-11-18 14:33:52.619 | CleanupOperatio | Test worker    | INFO : Writing new known databases table: [RemoteFile[name=database-A-0000000004]]
18-11-18 14:33:52.619 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000001] ...
18-11-18 14:33:52.619 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000001]-> Temp. remote file: RemoteFile[name=temp-HHCud-database-A-0000000001]
18-11-18 14:33:52.619 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000002] ...
18-11-18 14:33:52.619 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000002]-> Temp. remote file: RemoteFile[name=temp-hZyyC-database-A-0000000002]
18-11-18 14:33:52.619 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000003] ...
18-11-18 14:33:52.619 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000003]-> Temp. remote file: RemoteFile[name=temp-mkktf-database-A-0000000003]
18-11-18 14:33:52.619 | CleanupOperatio | Test worker    | INFO :    + Uploading new file RemoteFile[name=database-A-0000000004] from local file /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000004 ...
18-11-18 14:33:52.620 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-IOoXy-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
18-11-18 14:33:52.620 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:52.620 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:52.620 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:52.620 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-cleanup-4802849021591183702.tmp -> Temp. remote file: RemoteFile[name=temp-OVDCG-cleanup-1], final location: RemoteFile[name=cleanup-1]
18-11-18 14:33:52.620 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupNumber  = 1
18-11-18 14:33:52.620 | CleanupOperatio | Test worker    | INFO : Cleanup: COMMITTING TX ...
18-11-18 14:33:52.620 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:33:52.621 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-transaction-2404313093941123040.tmp
18-11-18 14:33:52.621 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@6e71e4fd) ...
18-11-18 14:33:52.621 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-28904220] ...
18-11-18 14:33:52.621 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000001] to temp. file RemoteFile[name=temp-HHCud-database-A-0000000001] ...
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000002] to temp. file RemoteFile[name=temp-hZyyC-database-A-0000000002] ...
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000003] to temp. file RemoteFile[name=temp-mkktf-database-A-0000000003] ...
18-11-18 14:33:52.622 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6bc23ebd) ...
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-IOoXy-database-A-0000000004] ...
18-11-18 14:33:52.622 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@3b12376) ...
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-cleanup-4802849021591183702.tmp to temp. file RemoteFile[name=temp-OVDCG-cleanup-1] ...
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-IOoXy-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-OVDCG-cleanup-1] to final location RemoteFile[name=cleanup-1] ...
18-11-18 14:33:52.622 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-28904220] ...
18-11-18 14:33:52.623 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:33:52.623 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-HHCud-database-A-0000000001]  ...
18-11-18 14:33:52.623 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-hZyyC-database-A-0000000002]  ...
18-11-18 14:33:52.623 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-mkktf-database-A-0000000003]  ...
18-11-18 14:33:52.623 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:33:52.626 | CleanupOperatio | Test worker    | INFO : Cleanup: SUCCESS COMMITTING TX.
18-11-18 14:33:52.626 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupTime  = 1542551632
18-11-18 14:33:52.628 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-cleanup-A-1542551631404] ...
18-11-18 14:33:52.628 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-cleanup-A-1542551631404]
18-11-18 14:33:52.628 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:52.628 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:52.628 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupEndSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupEndSyncExternalEvent@38c07867) ...
18-11-18 14:33:52.629 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:52.629 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:52.629 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:52.629 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:52.630 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.630 | UpOperation     | Test worker    | INFO : 
18-11-18 14:33:52.630 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:33:52.630 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.630 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@53bc8435) ...
18-11-18 14:33:52.631 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.631 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:52.631 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:52.631 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.631 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:33:52.631 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:52.631 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@166a2ee6) ...
18-11-18 14:33:52.631 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:52.632 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:52.632 | StatusOperation | Test worker    | FINE : - New file: file1 (copy).jpg
18-11-18 14:33:52.632 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@720a222f) ...
18-11-18 14:33:52.632 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:52.633 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.633 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:52.633 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:52.633 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.633 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@c9bf49) ...
18-11-18 14:33:52.633 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:52.633 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:52.633 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:33:52.633 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3fc85599) ...
18-11-18 14:33:52.633 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:33:52.633 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551632629] ...
18-11-18 14:33:52.633 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551632629]
18-11-18 14:33:52.633 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551632629] ...
18-11-18 14:33:52.634 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.634 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:33:52.634 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:33:52.634 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@2e6f4413) ...
18-11-18 14:33:52.634 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:33:52.634 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1 (copy).jpg
18-11-18 14:33:52.635 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1 (copy).jpg
18-11-18 14:33:52.635 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 9bb08a6f701dc04ea148a89d424389462d373c92
18-11-18 14:33:52.636 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 9bb08a6f701dc04ea148a89d424389462d373c92 > /tmp/syncanytest/syncany-181118143132272-50144-client-A/file1 (copy).jpg
18-11-18 14:33:52.636 | Indexer         | AsyncI/syncany | FINE : - /File: file1 (copy).jpg (checksum 9bb08a6f701dc04ea148a89d424389462d373c92)
18-11-18 14:33:52.636 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: file1 (copy).jpg, checksum: 9bb08a6f701dc04ea148a89d424389462d373c92)
18-11-18 14:33:52.636 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file file1 (copy).jpg
18-11-18 14:33:52.636 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:52 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:52.636 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
18-11-18 14:33:52.636 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@56cb4b50) ...
18-11-18 14:33:52.636 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@5f627e8d) ...
18-11-18 14:33:52.636 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551632634, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:52.637 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:33:52.637 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
18-11-18 14:33:52.637 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:33:52.637 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1542551632637, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:52.637 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1542551632637 to file /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000005 ... 
18-11-18 14:33:52.637 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000005 ...
18-11-18 14:33:52.638 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:33:52.638 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000005 to RemoteFile[name=database-A-0000000005] ...
18-11-18 14:33:52.638 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000005 -> Temp. remote file: RemoteFile[name=temp-SLikW-database-A-0000000005], final location: RemoteFile[name=database-A-0000000005]
18-11-18 14:33:52.638 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:33:52.638 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:33:52.639 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-transaction-4643376446928752586.tmp
18-11-18 14:33:52.639 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@375b8f79) ...
18-11-18 14:33:52.639 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-54a270f] ...
18-11-18 14:33:52.639 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:33:52.639 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@3d73da3) ...
18-11-18 14:33:52.639 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000005 to temp. file RemoteFile[name=temp-SLikW-database-A-0000000005] ...
18-11-18 14:33:52.639 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-SLikW-database-A-0000000005] to final location RemoteFile[name=database-A-0000000005] ...
18-11-18 14:33:52.639 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-54a270f] ...
18-11-18 14:33:52.640 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@77031c54) ...
18-11-18 14:33:52.640 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:33:52.640 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:33:52.640 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1542551632637) ...
18-11-18 14:33:52.641 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:33:52.645 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1542551632637, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:52.645 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:33:52.646 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:33:52.647 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:33:52.648 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551632647, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:33:52.648 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:33:52.649 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551632629] ...
18-11-18 14:33:52.650 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551632629]
18-11-18 14:33:52.650 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:52.650 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:52.650 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@2d924355) ...
18-11-18 14:33:52.650 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:52.651 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:52.651 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:52.651 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:52.652 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.652 | UpOperation     | Test worker    | INFO : 
18-11-18 14:33:52.652 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:33:52.652 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.652 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@e2328c3) ...
18-11-18 14:33:52.653 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.653 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:52.653 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:52.653 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.653 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:33:52.653 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:52.653 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@489e8604) ...
18-11-18 14:33:52.653 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:52.653 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:52.654 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@5ddfba66) ...
18-11-18 14:33:52.654 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:52.655 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.655 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:52.655 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:52.655 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.655 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@50880766) ...
18-11-18 14:33:52.655 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:52.655 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:52.655 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:33:52.655 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000005 is already known (in local database). Ignoring.
18-11-18 14:33:52.655 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@5170f465) ...
18-11-18 14:33:52.655 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:33:52.655 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551632651] ...
18-11-18 14:33:52.655 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551632651]
18-11-18 14:33:52.656 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551632651] ...
18-11-18 14:33:52.656 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.660 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:33:52.660 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:33:52.660 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:33:52.661 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=file1.jpg, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:52 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:52.661 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=file1.jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:51 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:52.661 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1542551632660, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:52.662 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:33:52.662 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
18-11-18 14:33:52.662 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:33:52.662 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1542551632662, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:52.662 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1542551632662 to file /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000006 ... 
18-11-18 14:33:52.662 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000006 ...
18-11-18 14:33:52.663 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:33:52.663 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000006 to RemoteFile[name=database-A-0000000006] ...
18-11-18 14:33:52.663 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000006 -> Temp. remote file: RemoteFile[name=temp-zBJll-database-A-0000000006], final location: RemoteFile[name=database-A-0000000006]
18-11-18 14:33:52.663 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:33:52.663 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:33:52.664 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-transaction-2123907177210453900.tmp
18-11-18 14:33:52.664 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@4c17e7e6) ...
18-11-18 14:33:52.664 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-5f24a9a0] ...
18-11-18 14:33:52.665 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:33:52.665 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@211589c7) ...
18-11-18 14:33:52.665 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000006 to temp. file RemoteFile[name=temp-zBJll-database-A-0000000006] ...
18-11-18 14:33:52.666 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-zBJll-database-A-0000000006] to final location RemoteFile[name=database-A-0000000006] ...
18-11-18 14:33:52.666 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-5f24a9a0] ...
18-11-18 14:33:52.666 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:33:52.666 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:33:52.666 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1542551632662) ...
18-11-18 14:33:52.666 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:33:52.667 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:33:52.671 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1542551632662, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:52.671 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:33:52.671 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:33:52.671 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551632667, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:33:52.671 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:33:52.672 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551632651] ...
18-11-18 14:33:52.675 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551632651]
18-11-18 14:33:52.675 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:52.676 | Cache           | Test worker    | INFO : Cache size okay (55 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:52.676 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@2973f6f1) ...
18-11-18 14:33:52.676 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.676 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.676 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:52.676 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:52.676 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.676 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.676 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.676 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.676 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:52.677 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:52.677 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.677 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.677 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:52.677 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:52.677 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:52.677 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:52.677 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.677 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.677 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.677 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.677 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:52.677 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:52.677 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:52.677 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:52.678 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.678 | CleanupOperatio | Test worker    | INFO : 
18-11-18 14:33:52.678 | CleanupOperatio | Test worker    | INFO : Running 'Cleanup' at client A ...
18-11-18 14:33:52.678 | CleanupOperatio | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.678 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = 1542551632
18-11-18 14:33:52.679 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.679 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:52.679 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:52.679 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.679 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:52.679 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@207434ab) ...
18-11-18 14:33:52.679 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:52.679 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:52.680 | StatusOperation | Test worker    | INFO : - No changes to local database
18-11-18 14:33:52.680 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@51ed9aff) ...
18-11-18 14:33:52.680 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:52.680 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:52.680 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:52.680 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:52.680 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@614a76f3) ...
18-11-18 14:33:52.680 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:52.681 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:52.681 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:52.681 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:52.681 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:52.681 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:52.681 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:52.681 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:52.681 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:52.681 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:52.681 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:33:52.681 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000005 is already known (in local database). Ignoring.
18-11-18 14:33:52.681 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000006 is already known (in local database). Ignoring.
18-11-18 14:33:52.681 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2e1e90d4) ...
18-11-18 14:33:52.681 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:52.681 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartSyncExternalEvent@1992baa1) ...
18-11-18 14:33:52.681 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartCleaningSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartCleaningSyncExternalEvent@2bddaa8e) ...
18-11-18 14:33:52.681 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-cleanup-A-1542551632677] ...
18-11-18 14:33:52.681 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-cleanup-A-1542551632677]
18-11-18 14:33:52.682 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-cleanup-A-1542551632677] ...
18-11-18 14:33:52.682 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:33:52.682 | CleanupOperatio | Test worker    | INFO : Cleanup: Waiting a while to be sure that no other actions are running ...
18-11-18 14:33:53.882 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = 1542551632
18-11-18 14:33:53.883 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:53.883 | StatusOperation | Test worker    | INFO : 
18-11-18 14:33:53.883 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:33:53.883 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:53.883 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:33:53.883 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@668efca6) ...
18-11-18 14:33:53.883 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-50144-client-A ...
18-11-18 14:33:53.884 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:33:53.884 | StatusOperation | Test worker    | INFO : - No changes to local database
18-11-18 14:33:53.884 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@7d5523f5) ...
18-11-18 14:33:53.884 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:53.884 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:53.884 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:33:53.884 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:53.884 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@29fdc7e5) ...
18-11-18 14:33:53.884 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:53.885 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-A' ...
18-11-18 14:33:53.885 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:53.885 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:53.885 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:53.885 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:53.885 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:53.885 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:53.885 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:53.885 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:53.885 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:33:53.885 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000005 is already known (in local database). Ignoring.
18-11-18 14:33:53.885 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000006 is already known (in local database). Ignoring.
18-11-18 14:33:53.885 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2a36b4ed) ...
18-11-18 14:33:53.885 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:53.885 | CleanupOperatio | Test worker    | INFO : Cleanup: Starting transaction.
18-11-18 14:33:53.887 | CleanupOperatio | Test worker    | INFO : - Old version removal: Found 1 file histories and 1 file versions that need cleaning.
18-11-18 14:33:53.888 | CleanupOperatio | Test worker    | INFO : - Deleting remote multichunks ...
18-11-18 14:33:53.888 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:53.888 | CleanupOperatio | Test worker    | INFO : - Merge remote files ...
18-11-18 14:33:53.888 | CleanupOperatio | Test worker    | INFO : Databases: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000005], RemoteFile[name=database-A-0000000006]]
18-11-18 14:33:53.889 | CleanupOperatio | Test worker    | INFO :    + Writing new merge file (all files up to 6) to /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000007 ...
18-11-18 14:33:53.891 | CleanupOperatio | Test worker    | INFO : Writing new known databases table: [RemoteFile[name=database-A-0000000007]]
18-11-18 14:33:53.891 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000004] ...
18-11-18 14:33:53.891 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000004]-> Temp. remote file: RemoteFile[name=temp-xTGXW-database-A-0000000004]
18-11-18 14:33:53.891 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000005] ...
18-11-18 14:33:53.891 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000005]-> Temp. remote file: RemoteFile[name=temp-hSKOl-database-A-0000000005]
18-11-18 14:33:53.891 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000006] ...
18-11-18 14:33:53.891 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000006]-> Temp. remote file: RemoteFile[name=temp-bgSlS-database-A-0000000006]
18-11-18 14:33:53.891 | CleanupOperatio | Test worker    | INFO :    + Uploading new file RemoteFile[name=database-A-0000000007] from local file /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000007 ...
18-11-18 14:33:53.891 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000007 -> Temp. remote file: RemoteFile[name=temp-hKvAf-database-A-0000000007], final location: RemoteFile[name=database-A-0000000007]
18-11-18 14:33:53.892 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:53.892 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/database-A-0000000006; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:53.892 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/database-A-0000000005; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:53.892 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=cleanup-1]-> Temp. remote file: RemoteFile[name=temp-okGQa-cleanup-1]
18-11-18 14:33:53.892 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-cleanup-5253739435307043318.tmp -> Temp. remote file: RemoteFile[name=temp-pdaKS-cleanup-2], final location: RemoteFile[name=cleanup-2]
18-11-18 14:33:53.892 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupNumber  = 2
18-11-18 14:33:53.892 | CleanupOperatio | Test worker    | INFO : Cleanup: COMMITTING TX ...
18-11-18 14:33:53.892 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:33:53.893 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-transaction-445367953593625320.tmp
18-11-18 14:33:53.893 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@4403889d) ...
18-11-18 14:33:53.893 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-54a5331c] ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000004] to temp. file RemoteFile[name=temp-xTGXW-database-A-0000000004] ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000005] to temp. file RemoteFile[name=temp-hSKOl-database-A-0000000005] ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000006] to temp. file RemoteFile[name=temp-bgSlS-database-A-0000000006] ...
18-11-18 14:33:53.894 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@687707ba) ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/database-A-0000000007 to temp. file RemoteFile[name=temp-hKvAf-database-A-0000000007] ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=cleanup-1] to temp. file RemoteFile[name=temp-okGQa-cleanup-1] ...
18-11-18 14:33:53.894 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1ca79208) ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-50144-client-A/.syncany/cache/temp-cleanup-5253739435307043318.tmp to temp. file RemoteFile[name=temp-pdaKS-cleanup-2] ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-hKvAf-database-A-0000000007] to final location RemoteFile[name=database-A-0000000007] ...
18-11-18 14:33:53.894 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-pdaKS-cleanup-2] to final location RemoteFile[name=cleanup-2] ...
18-11-18 14:33:53.895 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-54a5331c] ...
18-11-18 14:33:53.895 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:33:53.895 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-xTGXW-database-A-0000000004]  ...
18-11-18 14:33:53.895 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-hSKOl-database-A-0000000005]  ...
18-11-18 14:33:53.895 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-bgSlS-database-A-0000000006]  ...
18-11-18 14:33:53.895 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-okGQa-cleanup-1]  ...
18-11-18 14:33:53.895 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:33:53.898 | CleanupOperatio | Test worker    | INFO : Cleanup: SUCCESS COMMITTING TX.
18-11-18 14:33:53.898 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupTime  = 1542551633
18-11-18 14:33:53.900 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-cleanup-A-1542551632677] ...
18-11-18 14:33:53.900 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-cleanup-A-1542551632677]
18-11-18 14:33:53.900 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:53.901 | Cache           | Test worker    | INFO : Cache size okay (56 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:53.901 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupEndSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupEndSyncExternalEvent@49f52626) ...
18-11-18 14:33:53.901 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-B' ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:53.901 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-50144-client-B' ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:33:53.901 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:33:53.901 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:33:53.910 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
18-11-18 14:33:53.910 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
18-11-18 14:33:53.916 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
18-11-18 14:33:53.918 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
18-11-18 14:33:53.919 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
18-11-18 14:33:53.924 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
18-11-18 14:33:53.924 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
18-11-18 14:33:53.924 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
18-11-18 14:33:53.924 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
18-11-18 14:33:53.926 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.928 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.931 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.933 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.935 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.941 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.943 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.945 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
18-11-18 14:33:53.947 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
18-11-18 14:33:53.949 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
18-11-18 14:33:53.950 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
18-11-18 14:33:53.952 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
18-11-18 14:33:53.952 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
18-11-18 14:33:53.953 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
18-11-18 14:33:53.955 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
18-11-18 14:33:53.957 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
18-11-18 14:33:53.960 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
18-11-18 14:33:53.962 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
18-11-18 14:33:53.964 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
18-11-18 14:33:53.966 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
18-11-18 14:33:53.966 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
18-11-18 14:33:53.968 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
18-11-18 14:33:53.970 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
18-11-18 14:33:53.972 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
18-11-18 14:33:53.974 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
18-11-18 14:33:53.975 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
18-11-18 14:33:53.976 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
18-11-18 14:33:53.979 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
18-11-18 14:33:53.979 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
18-11-18 14:33:53.979 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
18-11-18 14:33:53.981 | DownOperation   | Test worker    | INFO : 
18-11-18 14:33:53.981 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
18-11-18 14:33:53.981 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:53.981 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@4e3fb0cd) ...
18-11-18 14:33:53.981 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:33:53.993 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:53.993 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:33:53.993 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
18-11-18 14:33:53.993 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:33:53.993 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2cf55544) ...
18-11-18 14:33:53.993 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:33:53.993 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/cleanup-2; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:53.996 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000007 is new.
18-11-18 14:33:53.996 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7422d506) ...
18-11-18 14:33:53.996 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@3113fc25) ...
18-11-18 14:33:53.996 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1542551633901] ...
18-11-18 14:33:53.996 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1542551633901]
18-11-18 14:33:53.997 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1542551633901] ...
18-11-18 14:33:53.997 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
18-11-18 14:33:53.997 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000007 to local cache at /tmp/syncanytest/syncany-181118143132272-50144-client-B/.syncany/cache/database-A-0000000007
18-11-18 14:33:53.997 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@57efec66) ...
18-11-18 14:33:53.997 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
18-11-18 14:33:53.997 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-50144-client-B/.syncany/cache/database-A-0000000007 ...
18-11-18 14:33:53.998 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1542551631304
18-11-18 14:33:53.999 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1542551632637
18-11-18 14:33:53.999 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-50144-repo/databases/database-A-0000000007; maybe invalid file name pattern. Ignoring file.
18-11-18 14:33:53.999 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
18-11-18 14:33:53.999 | DownOperation   | Test worker    | INFO : Cleanup occurred. Capturing local file histories, then deleting entire database ...
18-11-18 14:33:53.999 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM multichunk_muddy; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM multichunk_chunk; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM multichunk; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM fileversion; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM filehistory; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM filecontent_chunk; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM filecontent; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM databaseversion_vectorclock; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM chunk; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM databaseversion; 
18-11-18 14:33:54.000 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM known_databases; 
18-11-18 14:33:54.000 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupNumber  = 2
18-11-18 14:33:54.000 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupTime  = 1542551634
18-11-18 14:33:54.000 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1542551631304, A/(A2)/T=1542551632637], B=[]}
18-11-18 14:33:54.000 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
18-11-18 14:33:54.000 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1542551631304
18-11-18 14:33:54.001 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1542551632637
18-11-18 14:33:54.001 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
18-11-18 14:33:54.001 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1542551631304
18-11-18 14:33:54.001 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1542551632637
18-11-18 14:33:54.001 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
18-11-18 14:33:54.001 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
18-11-18 14:33:54.001 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
18-11-18 14:33:54.001 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
18-11-18 14:33:54.001 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1542551631304, A/(A2)/T=1542551632637]
18-11-18 14:33:54.001 | DownOperation   | Test worker    | INFO : - Cleanup occurred: true
18-11-18 14:33:54.001 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1542551631304, A/(A2)/T=1542551632637]
18-11-18 14:33:54.001 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
18-11-18 14:33:54.001 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-50144-client-B/.syncany/cache/database-A-0000000007 ...
18-11-18 14:33:54.002 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1542551631304
18-11-18 14:33:54.002 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1542551632637
18-11-18 14:33:54.002 | DownOperation   | Test worker    | INFO : Determine file system actions ...
18-11-18 14:33:54.003 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:33:54.003 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
18-11-18 14:33:54.003 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
18-11-18 14:33:54.003 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:33:54.003 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:52 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:33:54.003 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file file1 (copy).jpg
18-11-18 14:33:54.003 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:52 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-50144-client-B/file1 (copy).jpg
18-11-18 14:33:54.003 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:52 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:33:54.003 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions (for deleted histories in winner's branch)...
18-11-18 14:33:54.004 | DownOperation   | Test worker    | INFO :   + Adding multichunk f64956361c96c84f9a06e68853bc7070a112cd33 to download list ...
18-11-18 14:33:54.004 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
18-11-18 14:33:54.004 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@20c932c7) ...
18-11-18 14:33:54.004 | Downloader      | Test worker    | INFO :   + Downloading multichunk f64956361c96c84f9a06e68853bc7070a112cd33 ...
18-11-18 14:33:54.004 | Downloader      | Test worker    | INFO :   + Decrypting multichunk f64956361c96c84f9a06e68853bc7070a112cd33 ...
18-11-18 14:33:54.004 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk f64956361c96c84f9a06e68853bc7070a112cd33 ...
18-11-18 14:33:54.005 | FileSystemActio | Test worker    | INFO :    Sorted actions:
18-11-18 14:33:54.005 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:52 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:33:54.005 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
18-11-18 14:33:54.005 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:33:51 UTC 2018, linkTarget=null, checksum=9bb08a6f701dc04ea148a89d424389462d373c92, updated=Sun Nov 18 14:33:52 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:33:54.006 | Assembler       | Test worker    | INFO :      - Creating file file1 (copy).jpg to /tmp/syncanytest/syncany-181118143132272-50144-client-B/.syncany/cache/temp-reconstructedFileVersion-7463636503361912485.tmp ...
18-11-18 14:33:54.007 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
18-11-18 14:33:54.007 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
18-11-18 14:33:54.007 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
18-11-18 14:33:54.007 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1542551631304, chunks=1, multiChunks=1, fileContents=1, fileHistories=0]
18-11-18 14:33:54.008 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
18-11-18 14:33:54.008 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1542551632637, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:33:54.012 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1542551633901] ...
18-11-18 14:33:54.012 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1542551633901]
18-11-18 14:33:54.013 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:33:54.013 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
18-11-18 14:33:54.013 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@70424ee8) ...
18-11-18 14:33:54.013 | DownOperation   | Test worker    | INFO : Sync down done.