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

1

tests

0

failures

0

ignored

2.807s

duration

100%

successful

Tests

Test Duration Result
testChangeAttributes 2.807s passed

Standard error

29-3-20 17:53:25.548 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.548 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
29-3-20 17:53:25.575 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:25.576 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:25.586 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:25.588 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:25.589 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:25.592 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:25.592 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:25.592 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:25.592 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:25.593 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.595 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.596 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.597 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.599 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.600 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.602 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.603 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:25.604 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:25.605 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:25.607 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:25.616 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:25.616 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:25.617 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:25.619 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:25.621 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:25.622 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:25.623 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:25.624 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:25.625 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:25.625 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:25.626 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:25.628 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:25.629 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:25.631 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:25.631 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:25.632 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:25.637 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:25.637 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:25.637 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:25.642 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.643 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.643 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.643 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.643 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.643 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.643 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.643 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:25.644 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:25.644 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.644 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.644 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.644 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.644 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.644 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.644 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:25.644 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:25.652 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.652 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:25.652 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:25.652 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.653 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@18850334) ...
29-3-20 17:53:25.653 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.653 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:25.653 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:25.653 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.653 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:53:25.653 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:25.653 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3872d371) ...
29-3-20 17:53:25.654 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:25.654 | StatusOperation | Test worker    | FINE : - New file: file1.jpg
29-3-20 17:53:25.654 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:25.654 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@19f2a50e) ...
29-3-20 17:53:25.654 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:25.654 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.654 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:25.654 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:25.654 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.654 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6cbe1403) ...
29-3-20 17:53:25.655 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:25.655 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1b9fbb19) ...
29-3-20 17:53:25.655 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:25.655 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504405644] ...
29-3-20 17:53:25.655 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504405644]
29-3-20 17:53:25.655 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504405644] ...
29-3-20 17:53:25.656 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.661 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:25.666 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:25.667 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@636b728d) ...
29-3-20 17:53:25.667 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:25.667 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1.jpg
29-3-20 17:53:25.667 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1.jpg
29-3-20 17:53:25.668 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 396884dca5e20f386ca8600fc802e500359ae2f7
29-3-20 17:53:25.668 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk d866fcfe1f036f3946d4beb99d9e30620e41d78a
29-3-20 17:53:25.669 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 396884dca5e20f386ca8600fc802e500359ae2f7 > d866fcfe1f036f3946d4beb99d9e30620e41d78a
29-3-20 17:53:25.669 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 396884dca5e20f386ca8600fc802e500359ae2f7 > /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1.jpg
29-3-20 17:53:25.669 | Indexer         | AsyncI/syncany | FINE : - /File: file1.jpg (checksum 396884dca5e20f386ca8600fc802e500359ae2f7)
29-3-20 17:53:25.670 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: file1.jpg, checksum: 396884dca5e20f386ca8600fc802e500359ae2f7)
29-3-20 17:53:25.670 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file file1.jpg
29-3-20 17:53:25.670 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=file1.jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:25 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:25.670 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:25.670 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@2ec6a746) ...
29-3-20 17:53:25.671 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk d866fcfe1f036f3946d4beb99d9e30620e41d78a
29-3-20 17:53:25.671 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@42c58aa3) ...
29-3-20 17:53:25.671 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504405666, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:53:25.671 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:25.671 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
29-3-20 17:53:25.671 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:25.672 | UpOperation     | Test worker    | INFO : - Uploading multichunk d866fcfe1f036f3946d4beb99d9e30620e41d78a from /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a to RemoteFile[name=multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a] ...
29-3-20 17:53:25.672 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a -> Temp. remote file: RemoteFile[name=temp-ixcbR-multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a], final location: RemoteFile[name=multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a]
29-3-20 17:53:25.672 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1585504405671, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:53:25.672 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1585504405671 to file /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000001 ... 
29-3-20 17:53:25.672 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:25.672 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:25.672 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:25.672 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-qWaPT-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
29-3-20 17:53:25.673 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:25.673 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:25.673 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-transaction-485362937025126035.tmp
29-3-20 17:53:25.673 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@36fc234b) ...
29-3-20 17:53:25.673 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-70d2c667] ...
29-3-20 17:53:25.674 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:25.674 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@48a6ab6a) ...
29-3-20 17:53:25.674 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a to temp. file RemoteFile[name=temp-ixcbR-multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a] ...
29-3-20 17:53:25.674 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6d2fa53) ...
29-3-20 17:53:25.674 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-qWaPT-database-A-0000000001] ...
29-3-20 17:53:25.674 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-ixcbR-multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a] to final location RemoteFile[name=multichunk-d866fcfe1f036f3946d4beb99d9e30620e41d78a] ...
29-3-20 17:53:25.674 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-qWaPT-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:25.674 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-70d2c667] ...
29-3-20 17:53:25.674 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:25.675 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:25.675 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1585504405671) ...
29-3-20 17:53:25.676 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:25.676 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@3f227930) ...
29-3-20 17:53:25.678 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:25.681 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1585504405671, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:53:25.681 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:25.681 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:25.681 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504405678, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:25.681 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:25.682 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504405644] ...
29-3-20 17:53:25.687 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504405644]
29-3-20 17:53:25.687 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:25.688 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:25.688 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@6d38289a) ...
29-3-20 17:53:25.688 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.688 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.688 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.688 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.688 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.688 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.688 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:25.688 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:25.689 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.689 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.689 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.689 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.689 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.689 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.689 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:25.689 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:25.692 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.692 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:25.692 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:25.692 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.692 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@ddd3165) ...
29-3-20 17:53:25.693 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.693 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:25.693 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:25.693 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.693 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:53:25.693 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:25.693 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@6ba17710) ...
29-3-20 17:53:25.693 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:25.694 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:25.694 | StatusOperation | Test worker    | FINE : - New file: file1 (copy).jpg
29-3-20 17:53:25.694 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@6c167c2a) ...
29-3-20 17:53:25.694 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:25.695 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.695 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:25.695 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:25.695 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.695 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@558f3f07) ...
29-3-20 17:53:25.695 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:25.695 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:25.695 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@72b9c38d) ...
29-3-20 17:53:25.695 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:25.695 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504405689] ...
29-3-20 17:53:25.695 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504405689]
29-3-20 17:53:25.695 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504405689] ...
29-3-20 17:53:25.696 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.698 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:25.698 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:25.699 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@40a18ecc) ...
29-3-20 17:53:25.699 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:25.699 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1 (copy).jpg
29-3-20 17:53:25.699 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1 (copy).jpg
29-3-20 17:53:25.700 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 396884dca5e20f386ca8600fc802e500359ae2f7
29-3-20 17:53:25.700 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 396884dca5e20f386ca8600fc802e500359ae2f7 > /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1 (copy).jpg
29-3-20 17:53:25.704 | Indexer         | AsyncI/syncany | FINE : - /File: file1 (copy).jpg (checksum 396884dca5e20f386ca8600fc802e500359ae2f7)
29-3-20 17:53:25.705 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: file1 (copy).jpg, checksum: 396884dca5e20f386ca8600fc802e500359ae2f7)
29-3-20 17:53:25.705 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file file1 (copy).jpg
29-3-20 17:53:25.705 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:25 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:25.705 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:25.705 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@210e8538) ...
29-3-20 17:53:25.705 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@10a01112) ...
29-3-20 17:53:25.705 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504405698, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:25.705 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:25.706 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
29-3-20 17:53:25.706 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:25.706 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1585504405706, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:25.706 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1585504405706 to file /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000002 ... 
29-3-20 17:53:25.706 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000002 ...
29-3-20 17:53:25.706 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:25.706 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
29-3-20 17:53:25.706 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-LMEGW-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
29-3-20 17:53:25.707 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:25.707 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:25.707 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-transaction-4932378607719619351.tmp
29-3-20 17:53:25.707 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@461c5dc6) ...
29-3-20 17:53:25.707 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-2d9b112c] ...
29-3-20 17:53:25.707 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:25.708 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6dffbf03) ...
29-3-20 17:53:25.708 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-LMEGW-database-A-0000000002] ...
29-3-20 17:53:25.708 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-LMEGW-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
29-3-20 17:53:25.708 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-2d9b112c] ...
29-3-20 17:53:25.708 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:25.708 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:25.708 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1585504405706) ...
29-3-20 17:53:25.709 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:25.710 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@9f36060) ...
29-3-20 17:53:25.712 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1585504405706, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:25.712 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:25.712 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:25.713 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:25.713 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504405713, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:25.713 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:25.714 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504405689] ...
29-3-20 17:53:25.719 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504405689]
29-3-20 17:53:25.719 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:25.719 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:25.719 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@1176a6a7) ...
29-3-20 17:53:25.719 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.719 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.719 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.719 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.719 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.719 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.719 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.719 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.719 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.719 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.719 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.720 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.720 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.720 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.720 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:25.720 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:25.720 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.720 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.720 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.720 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.720 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.720 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.720 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:25.720 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:25.727 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.727 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:25.727 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:25.727 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.727 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6c5d468a) ...
29-3-20 17:53:25.728 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.728 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:25.728 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:25.728 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.728 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:53:25.728 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:25.728 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@31b1c544) ...
29-3-20 17:53:25.729 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:25.730 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:25.730 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@6c903723) ...
29-3-20 17:53:25.730 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:25.731 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.731 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:25.731 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:25.731 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.731 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2a427d0b) ...
29-3-20 17:53:25.731 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:25.732 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:25.732 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:25.732 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@70db294e) ...
29-3-20 17:53:25.732 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:25.732 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504405720] ...
29-3-20 17:53:25.732 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504405720]
29-3-20 17:53:25.732 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504405720] ...
29-3-20 17:53:25.733 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.733 | ActionFileHandl | ActRenewTim    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-cleanup-A-1585504285712] ...
29-3-20 17:53:25.733 | ActionFileHandl | ActRenewTim    | INFO : Uploading action file: RemoteFile[name=action-cleanup-A-1585504405733]
29-3-20 17:53:25.736 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:25.734 | UnreliableLocal | ActRenewTim    | INFO : Operation successful:     abs=365 rel=31 op=upload upload(/tmp/syncany-action-11646774571886447534.tmp, action-cleanup-A-1585504405733)
29-3-20 17:53:25.738 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:25.738 | UnreliableLocal | ActRenewTim    | INFO : Operation successful:     abs=366 rel=173 op=connect connect
29-3-20 17:53:25.738 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:25.738 | ActionFileHandl | ActRenewTim    | INFO : Deleting action file: RemoteFile[name=action-cleanup-A-1585504285712]
29-3-20 17:53:25.738 | UnreliableLocal | ActRenewTim    | INFO : Operation successful:     abs=367 rel=32 op=delete delete(action-cleanup-A-1585504285712)
29-3-20 17:53:25.738 | UnreliableLocal | ActRenewTim    | INFO : Operation successful:     abs=368 rel=174 op=connect connect
29-3-20 17:53:25.740 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=file1 (copy).jpg, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:25 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:25.740 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:25 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:25.740 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1585504405738, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:25.746 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:25.746 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
29-3-20 17:53:25.746 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:25.747 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1585504405746, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:25.747 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1585504405746 to file /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000003 ... 
29-3-20 17:53:25.747 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000003 ...
29-3-20 17:53:25.747 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:25.747 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
29-3-20 17:53:25.747 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-vGQwg-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
29-3-20 17:53:25.747 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:25.747 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:25.748 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-transaction-2234376910704526597.tmp
29-3-20 17:53:25.748 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@642cd6e4) ...
29-3-20 17:53:25.748 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-5e562622] ...
29-3-20 17:53:25.748 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:25.748 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@49fa4adb) ...
29-3-20 17:53:25.748 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-vGQwg-database-A-0000000003] ...
29-3-20 17:53:25.749 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-vGQwg-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
29-3-20 17:53:25.749 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-5e562622] ...
29-3-20 17:53:25.749 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:25.749 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:25.749 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1585504405746) ...
29-3-20 17:53:25.749 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:25.752 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1585504405746, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:25.752 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:25.752 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:25.754 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:25.754 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504405754, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:25.754 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:25.755 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504405720] ...
29-3-20 17:53:25.760 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504405720]
29-3-20 17:53:25.760 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:25.760 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:25.760 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@16d27b53) ...
29-3-20 17:53:25.761 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.761 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:25.761 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:25.761 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:25.768 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.768 | CleanupOperatio | Test worker    | INFO : 
29-3-20 17:53:25.768 | CleanupOperatio | Test worker    | INFO : Running 'Cleanup' at client A ...
29-3-20 17:53:25.768 | CleanupOperatio | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.768 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = (not set)
29-3-20 17:53:25.768 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.768 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:25.768 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:25.768 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.768 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:25.768 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@511d200) ...
29-3-20 17:53:25.769 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:25.769 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:25.769 | StatusOperation | Test worker    | INFO : - No changes to local database
29-3-20 17:53:25.769 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@5f5705a1) ...
29-3-20 17:53:25.770 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:25.770 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:25.770 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:25.770 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:25.770 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6652fae7) ...
29-3-20 17:53:25.770 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:25.770 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:25.770 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:25.770 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:25.770 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:25.770 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:25.770 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:25.770 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:25.770 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:25.770 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:25.770 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:53:25.770 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:25.770 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@58f3df9e) ...
29-3-20 17:53:25.770 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:25.771 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartSyncExternalEvent@7f8c782d) ...
29-3-20 17:53:25.771 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartCleaningSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartCleaningSyncExternalEvent@ef820f9) ...
29-3-20 17:53:25.771 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-cleanup-A-1585504405761] ...
29-3-20 17:53:25.771 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-cleanup-A-1585504405761]
29-3-20 17:53:25.771 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-cleanup-A-1585504405761] ...
29-3-20 17:53:25.771 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:25.771 | CleanupOperatio | Test worker    | INFO : Cleanup: Waiting a while to be sure that no other actions are running ...
29-3-20 17:53:26.971 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = (not set)
29-3-20 17:53:26.972 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:26.972 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:26.972 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:26.972 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:26.972 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:26.972 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@518a97ad) ...
29-3-20 17:53:26.973 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:26.973 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:26.973 | StatusOperation | Test worker    | INFO : - No changes to local database
29-3-20 17:53:26.973 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@56f694d0) ...
29-3-20 17:53:26.974 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:26.974 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:26.974 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:26.974 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:26.974 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7d2387df) ...
29-3-20 17:53:26.974 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:26.974 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:26.974 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:26.974 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:26.974 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:26.974 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:26.974 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:26.974 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:26.974 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:26.974 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:26.974 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:53:26.974 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:26.974 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@a66b42a) ...
29-3-20 17:53:26.974 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:26.975 | CleanupOperatio | Test worker    | INFO : Cleanup: Starting transaction.
29-3-20 17:53:26.976 | CleanupOperatio | Test worker    | INFO : - Old version removal: Found 1 file histories and 1 file versions that need cleaning.
29-3-20 17:53:26.978 | CleanupOperatio | Test worker    | INFO : - Deleting remote multichunks ...
29-3-20 17:53:26.978 | CleanupOperatio | Test worker    | INFO : - Merge remote files ...
29-3-20 17:53:26.978 | CleanupOperatio | Test worker    | INFO : Databases: [RemoteFile[name=database-A-0000000001], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003]]
29-3-20 17:53:26.978 | CleanupOperatio | Test worker    | INFO :    + Writing new merge file (all files up to 3) to /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000004 ...
29-3-20 17:53:26.981 | CleanupOperatio | Test worker    | INFO : Writing new known databases table: [RemoteFile[name=database-A-0000000004]]
29-3-20 17:53:26.982 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:26.982 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000001]-> Temp. remote file: RemoteFile[name=temp-vrjqi-database-A-0000000001]
29-3-20 17:53:26.982 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000002] ...
29-3-20 17:53:26.982 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000002]-> Temp. remote file: RemoteFile[name=temp-gJlje-database-A-0000000002]
29-3-20 17:53:26.982 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000003] ...
29-3-20 17:53:26.983 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000003]-> Temp. remote file: RemoteFile[name=temp-cKjge-database-A-0000000003]
29-3-20 17:53:26.983 | CleanupOperatio | Test worker    | INFO :    + Uploading new file RemoteFile[name=database-A-0000000004] from local file /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000004 ...
29-3-20 17:53:26.983 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-XJuwQ-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
29-3-20 17:53:26.983 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:26.983 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:26.983 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:26.983 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-cleanup-18304412030049168073.tmp -> Temp. remote file: RemoteFile[name=temp-PpZCz-cleanup-1], final location: RemoteFile[name=cleanup-1]
29-3-20 17:53:26.984 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupNumber  = 1
29-3-20 17:53:26.984 | CleanupOperatio | Test worker    | INFO : Cleanup: COMMITTING TX ...
29-3-20 17:53:26.984 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:26.985 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-transaction-11112120673205676047.tmp
29-3-20 17:53:26.985 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@733cda8d) ...
29-3-20 17:53:26.985 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-3243bab7] ...
29-3-20 17:53:26.986 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:26.986 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000001] to temp. file RemoteFile[name=temp-vrjqi-database-A-0000000001] ...
29-3-20 17:53:26.986 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000002] to temp. file RemoteFile[name=temp-gJlje-database-A-0000000002] ...
29-3-20 17:53:26.986 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000003] to temp. file RemoteFile[name=temp-cKjge-database-A-0000000003] ...
29-3-20 17:53:26.987 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@7776afe) ...
29-3-20 17:53:26.987 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-XJuwQ-database-A-0000000004] ...
29-3-20 17:53:26.987 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1ad5b437) ...
29-3-20 17:53:26.987 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-cleanup-18304412030049168073.tmp to temp. file RemoteFile[name=temp-PpZCz-cleanup-1] ...
29-3-20 17:53:26.987 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-XJuwQ-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
29-3-20 17:53:26.988 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-PpZCz-cleanup-1] to final location RemoteFile[name=cleanup-1] ...
29-3-20 17:53:26.988 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-3243bab7] ...
29-3-20 17:53:26.988 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:26.988 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-vrjqi-database-A-0000000001]  ...
29-3-20 17:53:26.988 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-gJlje-database-A-0000000002]  ...
29-3-20 17:53:26.988 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-cKjge-database-A-0000000003]  ...
29-3-20 17:53:26.988 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:26.992 | CleanupOperatio | Test worker    | INFO : Cleanup: SUCCESS COMMITTING TX.
29-3-20 17:53:26.992 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupTime  = 1585504406
29-3-20 17:53:26.994 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-cleanup-A-1585504405761] ...
29-3-20 17:53:26.994 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-cleanup-A-1585504405761]
29-3-20 17:53:26.994 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:26.994 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:26.994 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupEndSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupEndSyncExternalEvent@2b4eaa86) ...
29-3-20 17:53:26.995 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:26.996 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:26.996 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:26.996 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:26.997 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:26.997 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:26.997 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:26.997 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:26.997 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@26de5ac4) ...
29-3-20 17:53:26.997 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:26.997 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:26.997 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:26.997 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:26.997 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:53:26.997 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:26.997 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@423e415a) ...
29-3-20 17:53:26.998 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:26.998 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:26.999 | StatusOperation | Test worker    | FINE : - New file: file1 (copy).jpg
29-3-20 17:53:26.999 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@58fa5b16) ...
29-3-20 17:53:26.999 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:26.999 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:26.999 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:26.999 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:26.999 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:26.999 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5b36041a) ...
29-3-20 17:53:26.999 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:26.999 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:27.000 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:53:27.000 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@46d1fb0) ...
29-3-20 17:53:27.000 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:27.000 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504406996] ...
29-3-20 17:53:27.000 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504406996]
29-3-20 17:53:27.000 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504406996] ...
29-3-20 17:53:27.000 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.001 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:27.001 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:27.001 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@6e1a2a43) ...
29-3-20 17:53:27.001 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:27.001 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1 (copy).jpg
29-3-20 17:53:27.001 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1 (copy).jpg
29-3-20 17:53:27.002 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 396884dca5e20f386ca8600fc802e500359ae2f7
29-3-20 17:53:27.002 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 396884dca5e20f386ca8600fc802e500359ae2f7 > /tmp/syncanytest/syncany-200329175039872-11056-client-A/file1 (copy).jpg
29-3-20 17:53:27.003 | Indexer         | AsyncI/syncany | FINE : - /File: file1 (copy).jpg (checksum 396884dca5e20f386ca8600fc802e500359ae2f7)
29-3-20 17:53:27.004 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: file1 (copy).jpg, checksum: 396884dca5e20f386ca8600fc802e500359ae2f7)
29-3-20 17:53:27.004 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file file1 (copy).jpg
29-3-20 17:53:27.004 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:27 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:27.004 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:27.004 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@30779a35) ...
29-3-20 17:53:27.005 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@79d42831) ...
29-3-20 17:53:27.005 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504407001, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:27.005 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@19e76e2b) ...
29-3-20 17:53:27.005 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:27.005 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
29-3-20 17:53:27.005 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:27.006 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1585504407005, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:27.006 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1585504407005 to file /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000005 ... 
29-3-20 17:53:27.006 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000005 ...
29-3-20 17:53:27.006 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:27.007 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:27.007 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000005 to RemoteFile[name=database-A-0000000005] ...
29-3-20 17:53:27.007 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000005 -> Temp. remote file: RemoteFile[name=temp-ceFUj-database-A-0000000005], final location: RemoteFile[name=database-A-0000000005]
29-3-20 17:53:27.007 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:27.007 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-transaction-9245868234197540738.tmp
29-3-20 17:53:27.008 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@5b630963) ...
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-52d3aa1d] ...
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:27.008 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@5fa45712) ...
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000005 to temp. file RemoteFile[name=temp-ceFUj-database-A-0000000005] ...
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-ceFUj-database-A-0000000005] to final location RemoteFile[name=database-A-0000000005] ...
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-52d3aa1d] ...
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:27.008 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:27.009 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1585504407005) ...
29-3-20 17:53:27.009 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:27.011 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1585504407005, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:27.011 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:27.011 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:27.011 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504407006, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:27.011 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:27.012 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504406996] ...
29-3-20 17:53:27.013 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504406996]
29-3-20 17:53:27.013 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:27.013 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:27.013 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@4a161201) ...
29-3-20 17:53:27.013 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:27.014 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:27.014 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:27.014 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:27.015 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:27.015 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:27.015 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:27.015 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:27.015 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.015 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:27.015 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:27.015 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:27.015 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@42268364) ...
29-3-20 17:53:27.016 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.016 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:27.016 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:27.016 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:27.016 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:53:27.016 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:27.016 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@5b94f554) ...
29-3-20 17:53:27.017 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:27.017 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:27.017 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@272d85d) ...
29-3-20 17:53:27.017 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:27.018 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.018 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:27.018 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:27.018 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:27.018 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@32c074b8) ...
29-3-20 17:53:27.018 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:27.018 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:27.018 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:53:27.018 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000005 is already known (in local database). Ignoring.
29-3-20 17:53:27.018 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@b18b042) ...
29-3-20 17:53:27.018 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:27.018 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504407015] ...
29-3-20 17:53:27.018 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504407015]
29-3-20 17:53:27.019 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504407015] ...
29-3-20 17:53:27.019 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.023 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:27.023 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:27.023 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:27.024 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=file1.jpg, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:27 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:27.024 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=file1.jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:25 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:27.024 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1585504407023, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:27.025 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:27.025 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
29-3-20 17:53:27.025 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:27.025 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1585504407025, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:27.025 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1585504407025 to file /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000006 ... 
29-3-20 17:53:27.025 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000006 ...
29-3-20 17:53:27.026 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:27.026 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000006 to RemoteFile[name=database-A-0000000006] ...
29-3-20 17:53:27.026 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000006 -> Temp. remote file: RemoteFile[name=temp-GHmPY-database-A-0000000006], final location: RemoteFile[name=database-A-0000000006]
29-3-20 17:53:27.026 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:27.026 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-transaction-15608318775655621470.tmp
29-3-20 17:53:27.027 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@beec8ce) ...
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-241aed1c] ...
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:27.027 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6412cb1) ...
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000006 to temp. file RemoteFile[name=temp-GHmPY-database-A-0000000006] ...
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-GHmPY-database-A-0000000006] to final location RemoteFile[name=database-A-0000000006] ...
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-241aed1c] ...
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:27.027 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:27.027 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1585504407025) ...
29-3-20 17:53:27.028 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:27.031 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1585504407025, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:27.031 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:27.031 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:27.032 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:27.033 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504407032, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:27.033 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:27.034 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504407015] ...
29-3-20 17:53:27.034 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504407015]
29-3-20 17:53:27.034 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:27.034 | Cache           | Test worker    | INFO : Cache size okay (55 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:27.034 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@456bb7af) ...
29-3-20 17:53:27.034 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:27.035 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:27.035 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:27.035 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:27.036 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.036 | CleanupOperatio | Test worker    | INFO : 
29-3-20 17:53:27.036 | CleanupOperatio | Test worker    | INFO : Running 'Cleanup' at client A ...
29-3-20 17:53:27.036 | CleanupOperatio | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:27.036 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = 1585504406
29-3-20 17:53:27.037 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.037 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:27.037 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:27.037 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:27.037 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:27.037 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@71253007) ...
29-3-20 17:53:27.037 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:27.037 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:27.037 | StatusOperation | Test worker    | INFO : - No changes to local database
29-3-20 17:53:27.038 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@294db713) ...
29-3-20 17:53:27.038 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:27.038 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:27.038 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:27.038 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:27.038 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5ffa3e9d) ...
29-3-20 17:53:27.038 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:27.038 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:27.038 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:27.038 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:27.050 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:27.050 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:27.050 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:27.050 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:27.050 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:27.050 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:27.050 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:53:27.050 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000005 is already known (in local database). Ignoring.
29-3-20 17:53:27.050 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000006 is already known (in local database). Ignoring.
29-3-20 17:53:27.050 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7af0be77) ...
29-3-20 17:53:27.051 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:27.051 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartSyncExternalEvent@67f78979) ...
29-3-20 17:53:27.051 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupStartCleaningSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupStartCleaningSyncExternalEvent@69774dcc) ...
29-3-20 17:53:27.051 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-cleanup-A-1585504407035] ...
29-3-20 17:53:27.051 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-cleanup-A-1585504407035]
29-3-20 17:53:27.051 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-cleanup-A-1585504407035] ...
29-3-20 17:53:27.051 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:27.051 | CleanupOperatio | Test worker    | INFO : Cleanup: Waiting a while to be sure that no other actions are running ...
29-3-20 17:53:28.251 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupTime  = 1585504406
29-3-20 17:53:28.252 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.252 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:28.252 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:28.252 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.252 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:28.252 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@2b4e2add) ...
29-3-20 17:53:28.253 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-11056-client-A ...
29-3-20 17:53:28.253 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:28.253 | StatusOperation | Test worker    | INFO : - No changes to local database
29-3-20 17:53:28.253 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@96e2967) ...
29-3-20 17:53:28.254 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.254 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.254 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:28.254 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.254 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7fa0a96f) ...
29-3-20 17:53:28.254 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.254 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-A' ...
29-3-20 17:53:28.254 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.254 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.254 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.254 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.254 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.254 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.254 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.254 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.254 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:53:28.254 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000005 is already known (in local database). Ignoring.
29-3-20 17:53:28.254 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000006 is already known (in local database). Ignoring.
29-3-20 17:53:28.254 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4c761b15) ...
29-3-20 17:53:28.254 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.255 | CleanupOperatio | Test worker    | INFO : Cleanup: Starting transaction.
29-3-20 17:53:28.256 | CleanupOperatio | Test worker    | INFO : - Old version removal: Found 1 file histories and 1 file versions that need cleaning.
29-3-20 17:53:28.258 | CleanupOperatio | Test worker    | INFO : - Deleting remote multichunks ...
29-3-20 17:53:28.259 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/cleanup-1; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.259 | CleanupOperatio | Test worker    | INFO : - Merge remote files ...
29-3-20 17:53:28.259 | CleanupOperatio | Test worker    | INFO : Databases: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000005], RemoteFile[name=database-A-0000000006]]
29-3-20 17:53:28.259 | CleanupOperatio | Test worker    | INFO :    + Writing new merge file (all files up to 6) to /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000007 ...
29-3-20 17:53:28.262 | CleanupOperatio | Test worker    | INFO : Writing new known databases table: [RemoteFile[name=database-A-0000000007]]
29-3-20 17:53:28.262 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000004] ...
29-3-20 17:53:28.262 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000004]-> Temp. remote file: RemoteFile[name=temp-rwWHY-database-A-0000000004]
29-3-20 17:53:28.262 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000005] ...
29-3-20 17:53:28.262 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000005]-> Temp. remote file: RemoteFile[name=temp-UBdIR-database-A-0000000005]
29-3-20 17:53:28.262 | CleanupOperatio | Test worker    | INFO :    + Deleting remote file RemoteFile[name=database-A-0000000006] ...
29-3-20 17:53:28.262 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=database-A-0000000006]-> Temp. remote file: RemoteFile[name=temp-WMBAt-database-A-0000000006]
29-3-20 17:53:28.262 | CleanupOperatio | Test worker    | INFO :    + Uploading new file RemoteFile[name=database-A-0000000007] from local file /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000007 ...
29-3-20 17:53:28.262 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000007 -> Temp. remote file: RemoteFile[name=temp-enZnn-database-A-0000000007], final location: RemoteFile[name=database-A-0000000007]
29-3-20 17:53:28.262 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.263 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/database-A-0000000006; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.263 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/database-A-0000000005; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.263 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for DELETE: RemoteFile[name=cleanup-1]-> Temp. remote file: RemoteFile[name=temp-gXxjU-cleanup-1]
29-3-20 17:53:28.263 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-cleanup-11631273701487556337.tmp -> Temp. remote file: RemoteFile[name=temp-GDben-cleanup-2], final location: RemoteFile[name=cleanup-2]
29-3-20 17:53:28.264 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupNumber  = 2
29-3-20 17:53:28.264 | CleanupOperatio | Test worker    | INFO : Cleanup: COMMITTING TX ...
29-3-20 17:53:28.264 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:28.265 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-transaction-810986359956827975.tmp
29-3-20 17:53:28.265 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@3089a2f9) ...
29-3-20 17:53:28.266 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-6449fde3] ...
29-3-20 17:53:28.266 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:28.266 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000004] to temp. file RemoteFile[name=temp-rwWHY-database-A-0000000004] ...
29-3-20 17:53:28.266 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000005] to temp. file RemoteFile[name=temp-UBdIR-database-A-0000000005] ...
29-3-20 17:53:28.266 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=database-A-0000000006] to temp. file RemoteFile[name=temp-WMBAt-database-A-0000000006] ...
29-3-20 17:53:28.266 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@191a49aa) ...
29-3-20 17:53:28.266 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/database-A-0000000007 to temp. file RemoteFile[name=temp-enZnn-database-A-0000000007] ...
29-3-20 17:53:28.266 | RemoteTransacti | Test worker    | INFO : - Moving RemoteFile[name=cleanup-1] to temp. file RemoteFile[name=temp-gXxjU-cleanup-1] ...
29-3-20 17:53:28.267 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@373b72b7) ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-11056-client-A/.syncany/cache/temp-cleanup-11631273701487556337.tmp to temp. file RemoteFile[name=temp-GDben-cleanup-2] ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-enZnn-database-A-0000000007] to final location RemoteFile[name=database-A-0000000007] ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-GDben-cleanup-2] to final location RemoteFile[name=cleanup-2] ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-6449fde3] ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-rwWHY-database-A-0000000004]  ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-UBdIR-database-A-0000000005]  ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-WMBAt-database-A-0000000006]  ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : - Deleting temp. file RemoteFile[name=temp-gXxjU-cleanup-1]  ...
29-3-20 17:53:28.267 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:28.269 | CleanupOperatio | Test worker    | INFO : Cleanup: SUCCESS COMMITTING TX.
29-3-20 17:53:28.269 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupTime  = 1585504408
29-3-20 17:53:28.271 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-cleanup-A-1585504407035] ...
29-3-20 17:53:28.271 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-cleanup-A-1585504407035]
29-3-20 17:53:28.271 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.271 | Cache           | Test worker    | INFO : Cache size okay (56 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.271 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event CleanupEndSyncExternalEvent (org.syncany.operations.daemon.messages.CleanupEndSyncExternalEvent@468be3fe) ...
29-3-20 17:53:28.272 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-B' ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.272 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-11056-client-B' ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.272 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.272 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.282 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:28.282 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:28.287 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:28.289 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:28.290 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:28.293 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:28.294 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:28.294 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:28.294 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:28.295 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.297 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.298 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.300 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.301 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.303 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.304 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.306 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.307 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:28.309 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:28.310 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:28.311 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:28.311 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:28.312 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:28.314 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:28.315 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:28.317 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:28.318 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:28.319 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:28.320 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:28.320 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:28.322 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:28.324 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:28.325 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:28.327 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:28.327 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:28.329 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:28.330 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:28.330 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:28.330 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:28.332 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:28.332 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:28.332 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.332 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@1f07968) ...
29-3-20 17:53:28.332 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.333 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.333 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.333 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:28.333 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.333 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@4a1a64d7) ...
29-3-20 17:53:28.333 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.333 | LocalTransferMa | Test worker    | INFO : Cannot create instance of DatabaseRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/cleanup-2; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.334 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000007 is new.
29-3-20 17:53:28.334 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7c9e55f6) ...
29-3-20 17:53:28.334 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@21829c0c) ...
29-3-20 17:53:28.334 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504408272] ...
29-3-20 17:53:28.334 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504408272]
29-3-20 17:53:28.334 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504408272] ...
29-3-20 17:53:28.334 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:28.334 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000007 to local cache at /tmp/syncanytest/syncany-200329175039872-11056-client-B/.syncany/cache/database-A-0000000007
29-3-20 17:53:28.335 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@72b89083) ...
29-3-20 17:53:28.335 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:28.335 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-11056-client-B/.syncany/cache/database-A-0000000007 ...
29-3-20 17:53:28.336 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504405671
29-3-20 17:53:28.336 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504407005
29-3-20 17:53:28.337 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-11056-repo/databases/database-A-0000000007; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.337 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:28.337 | DownOperation   | Test worker    | INFO : Cleanup occurred. Capturing local file histories, then deleting entire database ...
29-3-20 17:53:28.338 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM multichunk_muddy; 
29-3-20 17:53:28.338 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM multichunk_chunk; 
29-3-20 17:53:28.338 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM multichunk; 
29-3-20 17:53:28.339 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM fileversion; 
29-3-20 17:53:28.339 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM filehistory; 
29-3-20 17:53:28.339 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM filecontent_chunk; 
29-3-20 17:53:28.339 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM filecontent; 
29-3-20 17:53:28.339 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM databaseversion_vectorclock; 
29-3-20 17:53:28.339 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM chunk; 
29-3-20 17:53:28.339 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM databaseversion; 
29-3-20 17:53:28.340 | SqlRunner       | Test worker    | INFO : SQL: DELETE FROM known_databases; 
29-3-20 17:53:28.340 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupNumber  = 2
29-3-20 17:53:28.340 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Writing cleanupTime  = 1585504408
29-3-20 17:53:28.341 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504405671, A/(A2)/T=1585504407005], B=[]}
29-3-20 17:53:28.341 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504405671
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1585504407005
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504405671
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1585504407005
29-3-20 17:53:28.341 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:28.341 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-3-20 17:53:28.341 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504405671, A/(A2)/T=1585504407005]
29-3-20 17:53:28.341 | DownOperation   | Test worker    | INFO : - Cleanup occurred: true
29-3-20 17:53:28.341 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1585504405671, A/(A2)/T=1585504407005]
29-3-20 17:53:28.341 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:28.341 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-11056-client-B/.syncany/cache/database-A-0000000007 ...
29-3-20 17:53:28.342 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504405671
29-3-20 17:53:28.343 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504407005
29-3-20 17:53:28.343 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:28.343 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.343 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:28.343 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:28.343 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:53:28.343 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:27 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.344 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file file1 (copy).jpg
29-3-20 17:53:28.344 | 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 Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:27 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-11056-client-B/file1 (copy).jpg
29-3-20 17:53:28.344 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:27 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.344 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions (for deleted histories in winner's branch)...
29-3-20 17:53:28.344 | DownOperation   | Test worker    | INFO :   + Adding multichunk d866fcfe1f036f3946d4beb99d9e30620e41d78a to download list ...
29-3-20 17:53:28.344 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:28.344 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@2e7e944e) ...
29-3-20 17:53:28.345 | Downloader      | Test worker    | INFO :   + Downloading multichunk d866fcfe1f036f3946d4beb99d9e30620e41d78a ...
29-3-20 17:53:28.345 | Downloader      | Test worker    | INFO :   + Decrypting multichunk d866fcfe1f036f3946d4beb99d9e30620e41d78a ...
29-3-20 17:53:28.345 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk d866fcfe1f036f3946d4beb99d9e30620e41d78a ...
29-3-20 17:53:28.346 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:28.346 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:27 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.346 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:28.346 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=file1 (copy).jpg, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:25 UTC 2020, linkTarget=null, checksum=396884dca5e20f386ca8600fc802e500359ae2f7, updated=Sun Mar 29 17:53:27 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.346 | Assembler       | Test worker    | INFO :      - Creating file file1 (copy).jpg to /tmp/syncanytest/syncany-200329175039872-11056-client-B/.syncany/cache/temp-reconstructedFileVersion-6287918144422692516.tmp ...
29-3-20 17:53:28.347 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:28.347 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:28.347 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-3-20 17:53:28.347 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1585504405671, chunks=1, multiChunks=1, fileContents=1, fileHistories=0]
29-3-20 17:53:28.348 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
29-3-20 17:53:28.348 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1585504407005, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.352 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504408272] ...
29-3-20 17:53:28.353 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504408272]
29-3-20 17:53:28.353 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.353 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.353 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@6c346592) ...
29-3-20 17:53:28.353 | DownOperation   | Test worker    | INFO : Sync down done.