Class org.syncany.tests.integration.scenarios.SymlinkSyncScenarioTest

3

tests

0

failures

0

ignored

0.868s

duration

100%

successful

Tests

Test Duration Result
testSymlinkMultipleUpsAndDowns 0.298s passed
testSymlinkOneUpOneDown 0.249s passed
testSymlinkSyncToNonExistingFolder 0.321s passed

Standard error

25-5-17 10:17:16.858 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:16.858 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
25-5-17 10:17:16.868 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:16.868 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-10410-client-A' ...
25-5-17 10:17:16.868 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:16.868 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:16.868 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:16.868 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:16.868 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:16.868 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:16.868 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:16.868 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:16.868 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:16.869 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-10410-client-A' ...
25-5-17 10:17:16.869 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:16.869 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:16.869 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:16.869 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:16.869 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:16.869 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:16.869 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:16.869 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:16.869 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:16.869 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:16.869 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:16.869 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:16.879 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:17:16.879 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:17:16.887 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:17:16.893 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:17:16.893 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:17:16.899 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:17:16.899 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:17:16.899 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:17:16.899 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
25-5-17 10:17:16.903 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.906 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.909 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.911 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.914 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.916 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.919 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.922 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:16.924 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
25-5-17 10:17:16.927 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
25-5-17 10:17:16.932 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
25-5-17 10:17:16.935 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:17:16.935 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:17:16.935 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:17:16.938 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:17:16.940 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:17:16.942 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:17:16.945 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:17:16.947 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:17:16.949 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:17:16.949 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
25-5-17 10:17:16.952 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
25-5-17 10:17:16.954 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
25-5-17 10:17:16.957 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
25-5-17 10:17:16.960 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:17:16.960 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
25-5-17 10:17:16.962 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
25-5-17 10:17:16.965 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:17:16.965 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:17:16.965 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
25-5-17 10:17:16.969 | UpOperation     | Test worker    | INFO : 
25-5-17 10:17:16.969 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:17:16.969 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:16.969 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2a7a3158) ...
25-5-17 10:17:16.970 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:16.970 | StatusOperation | Test worker    | INFO : 
25-5-17 10:17:16.970 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:17:16.970 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:16.970 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:17:16.970 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@226232a4) ...
25-5-17 10:17:16.970 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101614951-10410-client-A ...
25-5-17 10:17:16.971 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:17:16.971 | StatusOperation | Test worker    | FINE : - New file: symlink-name
25-5-17 10:17:16.971 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4937ce4a) ...
25-5-17 10:17:16.971 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:16.971 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:16.971 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:16.971 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:17:16.971 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:16.971 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@408452ed) ...
25-5-17 10:17:16.971 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:16.972 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@664e290f) ...
25-5-17 10:17:16.972 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:17:16.972 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707436869] ...
25-5-17 10:17:16.972 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707436869]
25-5-17 10:17:16.972 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707436869] ...
25-5-17 10:17:16.973 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:16.973 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:17:16.973 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:17:16.973 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@16be75b9) ...
25-5-17 10:17:16.973 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:17:16.973 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101614951-10410-client-A/symlink-name
25-5-17 10:17:16.973 | Indexer         | AsyncI/syncany | FINE : - /File: symlink-name (directory/symlink/0-byte-file)
25-5-17 10:17:16.974 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: symlink-name, SYMLINK)
25-5-17 10:17:16.974 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file symlink-name
25-5-17 10:17:16.974 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Thu May 25 10:17:16 UTC 2017, linkTarget=/etc/hosts, checksum=null, updated=Thu May 25 10:17:16 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
25-5-17 10:17:16.974 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
25-5-17 10:17:16.974 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@5fcf9e1f) ...
25-5-17 10:17:16.974 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@3d25b1b0) ...
25-5-17 10:17:16.974 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707436973, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:16.974 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:17:16.974 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
25-5-17 10:17:16.974 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:17:16.974 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1495707436974, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:16.975 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1495707436974 to file /tmp/syncanytest/syncany-170525101614951-10410-client-A/.syncany/cache/database-A-0000000001 ... 
25-5-17 10:17:16.975 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101614951-10410-client-A/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:16.975 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:17:16.975 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-10410-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
25-5-17 10:17:16.975 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101614951-10410-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-MQRtP-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
25-5-17 10:17:16.976 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:17:16.976 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:17:16.977 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101614951-10410-client-A/.syncany/cache/temp-transaction-8586423568156482922.tmp
25-5-17 10:17:16.977 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@1fa679b0) ...
25-5-17 10:17:16.977 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-7fb66948] ...
25-5-17 10:17:16.978 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:17:16.978 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@5588704f) ...
25-5-17 10:17:16.978 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-10410-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-MQRtP-database-A-0000000001] ...
25-5-17 10:17:16.978 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-MQRtP-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
25-5-17 10:17:16.978 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-7fb66948] ...
25-5-17 10:17:16.978 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:17:16.978 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:17:16.978 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1495707436974) ...
25-5-17 10:17:16.979 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:17:16.981 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@d68cc23) ...
25-5-17 10:17:16.984 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1495707436974, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:16.984 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:17:16.984 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:17:16.986 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:17:16.986 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707436986, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:17:16.986 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:17:16.988 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707436869] ...
25-5-17 10:17:16.989 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707436869]
25-5-17 10:17:16.989 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:16.989 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:16.989 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@29f0df06) ...
25-5-17 10:17:16.990 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:16.990 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:16.990 | FileVersionSqlD | Test worker    | INFO :  getFileTree(path = symlink-name, history = %, minSlash = 0, maxSlash = 0, date <= Sat Jan 01 01:01:01 UTC 2101, types = FILE, FOLDER, SYMLINK
25-5-17 10:17:16.993 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:16.993 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-10410-client-B' ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:16.994 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-10410-client-B' ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:16.994 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:16.994 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:17.004 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:17:17.004 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:17:17.013 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:17:17.015 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:17:17.016 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:17:17.021 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:17:17.021 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:17:17.022 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:17:17.022 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
25-5-17 10:17:17.024 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.027 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.029 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.032 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.034 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.037 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.039 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.042 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.044 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
25-5-17 10:17:17.047 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
25-5-17 10:17:17.049 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
25-5-17 10:17:17.051 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:17:17.051 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:17:17.052 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:17:17.054 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:17:17.056 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:17:17.059 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:17:17.061 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:17:17.063 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:17:17.065 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:17:17.065 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
25-5-17 10:17:17.068 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
25-5-17 10:17:17.070 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
25-5-17 10:17:17.073 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
25-5-17 10:17:17.076 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:17:17.076 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
25-5-17 10:17:17.079 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
25-5-17 10:17:17.081 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:17:17.081 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:17:17.081 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
25-5-17 10:17:17.084 | DownOperation   | Test worker    | INFO : 
25-5-17 10:17:17.084 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:17:17.084 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.084 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@57ca91a5) ...
25-5-17 10:17:17.085 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:17.086 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.086 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:17.086 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:17:17.086 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.086 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2e835076) ...
25-5-17 10:17:17.086 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:17.086 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
25-5-17 10:17:17.086 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@39699ef9) ...
25-5-17 10:17:17.086 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@2c0fcde9) ...
25-5-17 10:17:17.086 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707436994] ...
25-5-17 10:17:17.086 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707436994]
25-5-17 10:17:17.087 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707436994] ...
25-5-17 10:17:17.087 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:17:17.087 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-170525101614951-10410-client-B/.syncany/cache/database-A-0000000001
25-5-17 10:17:17.087 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@3c118dbe) ...
25-5-17 10:17:17.088 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:17:17.088 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101614951-10410-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.089 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707436974
25-5-17 10:17:17.090 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101614951-10410-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:17:17.090 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:17:17.090 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1495707436974], B=[]}
25-5-17 10:17:17.090 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:17:17.090 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707436974
25-5-17 10:17:17.090 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:17:17.090 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707436974
25-5-17 10:17:17.090 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:17:17.090 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:17:17.090 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:17:17.090 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
25-5-17 10:17:17.090 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707436974]
25-5-17 10:17:17.090 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:17:17.090 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1495707436974]
25-5-17 10:17:17.090 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:17:17.090 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101614951-10410-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.092 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707436974
25-5-17 10:17:17.092 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:17:17.093 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.093 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:17:17.093 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:17:17.093 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
25-5-17 10:17:17.093 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Thu May 25 10:17:16 UTC 2017, linkTarget=/etc/hosts, checksum=null, updated=Thu May 25 10:17:16 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
25-5-17 10:17:17.094 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file symlink-name
25-5-17 10:17:17.094 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Thu May 25 10:17:16 UTC 2017, linkTarget=/etc/hosts, checksum=null, updated=Thu May 25 10:17:16 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170525101614951-10410-client-B/symlink-name
25-5-17 10:17:17.094 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Thu May 25 10:17:16 UTC 2017, linkTarget=/etc/hosts, checksum=null, updated=Thu May 25 10:17:16 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.094 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:17:17.094 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:17:17.094 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Thu May 25 10:17:16 UTC 2017, linkTarget=/etc/hosts, checksum=null, updated=Thu May 25 10:17:16 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.094 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:17:17.094 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Thu May 25 10:17:16 UTC 2017, linkTarget=/etc/hosts, checksum=null, updated=Thu May 25 10:17:16 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.094 | FileSystemActio | Test worker    | INFO :      - Creating symlink at /tmp/syncanytest/syncany-170525101614951-10410-client-B/symlink-name (target: /etc/hosts) ...
25-5-17 10:17:17.094 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:17:17.094 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
25-5-17 10:17:17.094 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1495707436974, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.102 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707436994] ...
25-5-17 10:17:17.104 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707436994]
25-5-17 10:17:17.104 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:17.104 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:17.104 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@f6a6933) ...
25-5-17 10:17:17.104 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:17:17.111 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.113 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
25-5-17 10:17:17.123 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.123 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-31234-client-A' ...
25-5-17 10:17:17.123 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.123 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.123 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.123 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.123 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.123 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.123 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.123 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.124 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.124 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-31234-client-A' ...
25-5-17 10:17:17.124 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.124 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.124 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:17.124 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:17.124 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.124 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.124 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.124 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.124 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.124 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.124 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:17.124 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:17.138 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:17:17.138 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:17:17.146 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:17:17.149 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:17:17.150 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:17:17.156 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:17:17.156 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:17:17.156 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:17:17.156 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
25-5-17 10:17:17.159 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.162 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.166 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.168 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.171 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.173 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.176 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.178 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.181 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
25-5-17 10:17:17.183 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
25-5-17 10:17:17.186 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
25-5-17 10:17:17.192 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:17:17.192 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:17:17.192 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:17:17.195 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:17:17.198 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:17:17.200 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:17:17.203 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:17:17.205 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:17:17.208 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:17:17.208 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
25-5-17 10:17:17.211 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
25-5-17 10:17:17.214 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
25-5-17 10:17:17.216 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
25-5-17 10:17:17.219 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:17:17.220 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
25-5-17 10:17:17.223 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
25-5-17 10:17:17.226 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:17:17.226 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:17:17.226 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
25-5-17 10:17:17.229 | UpOperation     | Test worker    | INFO : 
25-5-17 10:17:17.229 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:17:17.229 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.229 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@3e9319a0) ...
25-5-17 10:17:17.230 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.230 | StatusOperation | Test worker    | INFO : 
25-5-17 10:17:17.230 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:17:17.230 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.230 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:17:17.230 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@56923e8a) ...
25-5-17 10:17:17.231 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101614951-31234-client-A ...
25-5-17 10:17:17.231 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:17:17.231 | StatusOperation | Test worker    | FINE : - New file: symlink-target
25-5-17 10:17:17.231 | StatusOperation | Test worker    | FINE : - New file: symlink-name
25-5-17 10:17:17.231 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@28bd74fd) ...
25-5-17 10:17:17.231 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:17.232 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.232 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:17.232 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:17:17.232 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.232 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@24403b0b) ...
25-5-17 10:17:17.232 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:17.232 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4777f912) ...
25-5-17 10:17:17.232 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:17:17.232 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707437124] ...
25-5-17 10:17:17.232 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707437124]
25-5-17 10:17:17.233 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707437124] ...
25-5-17 10:17:17.233 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.233 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:17:17.233 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:17:17.234 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@54e8b206) ...
25-5-17 10:17:17.237 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:17:17.237 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101614951-31234-client-A/symlink-name
25-5-17 10:17:17.245 | Indexer         | AsyncI/syncany | FINE : - /File: symlink-name (directory/symlink/0-byte-file)
25-5-17 10:17:17.246 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: symlink-name, SYMLINK)
25-5-17 10:17:17.246 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file symlink-name
25-5-17 10:17:17.246 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=symlink-target, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
25-5-17 10:17:17.246 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
25-5-17 10:17:17.246 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@69444bef) ...
25-5-17 10:17:17.246 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101614951-31234-client-A/symlink-target
25-5-17 10:17:17.246 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170525101614951-31234-client-A/symlink-target
25-5-17 10:17:17.247 | Indexer         | AsyncI/syncany | FINE : - Chunk new: e94f2a8f0238fa363a27afbdbfc469fc58153411
25-5-17 10:17:17.248 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk e607a6da7ea618cb14056fae5285ab3dc93db569
25-5-17 10:17:17.248 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: e94f2a8f0238fa363a27afbdbfc469fc58153411 > e607a6da7ea618cb14056fae5285ab3dc93db569
25-5-17 10:17:17.248 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: e94f2a8f0238fa363a27afbdbfc469fc58153411 > /tmp/syncanytest/syncany-170525101614951-31234-client-A/symlink-target
25-5-17 10:17:17.248 | Indexer         | AsyncI/syncany | FINE : - /File: symlink-target (checksum e94f2a8f0238fa363a27afbdbfc469fc58153411)
25-5-17 10:17:17.249 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: symlink-target, checksum: e94f2a8f0238fa363a27afbdbfc469fc58153411)
25-5-17 10:17:17.249 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file symlink-target
25-5-17 10:17:17.249 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=e94f2a8f0238fa363a27afbdbfc469fc58153411, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:17:17.249 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
25-5-17 10:17:17.249 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk e607a6da7ea618cb14056fae5285ab3dc93db569
25-5-17 10:17:17.249 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@468c51e5) ...
25-5-17 10:17:17.249 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707437233, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
25-5-17 10:17:17.249 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@5b235e11) ...
25-5-17 10:17:17.252 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:17:17.256 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:17:17.257 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
25-5-17 10:17:17.257 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:17:17.257 | UpOperation     | Test worker    | INFO : - Uploading multichunk e607a6da7ea618cb14056fae5285ab3dc93db569 from /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569 to RemoteFile[name=multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569] ...
25-5-17 10:17:17.257 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569 -> Temp. remote file: RemoteFile[name=temp-VbZnd-multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569], final location: RemoteFile[name=multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569]
25-5-17 10:17:17.257 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1495707437257, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
25-5-17 10:17:17.258 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1495707437257 to file /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/database-A-0000000001 ... 
25-5-17 10:17:17.258 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.258 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:17:17.258 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
25-5-17 10:17:17.258 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-WLplW-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
25-5-17 10:17:17.259 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:17:17.259 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:17:17.263 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/temp-transaction-208558071201916477.tmp
25-5-17 10:17:17.263 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@922fe45) ...
25-5-17 10:17:17.263 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-625e37e5] ...
25-5-17 10:17:17.263 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:17:17.263 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6c03d60f) ...
25-5-17 10:17:17.263 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569 to temp. file RemoteFile[name=temp-VbZnd-multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569] ...
25-5-17 10:17:17.264 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@3700e11d) ...
25-5-17 10:17:17.264 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-31234-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-WLplW-database-A-0000000001] ...
25-5-17 10:17:17.264 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-VbZnd-multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569] to final location RemoteFile[name=multichunk-e607a6da7ea618cb14056fae5285ab3dc93db569] ...
25-5-17 10:17:17.264 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-WLplW-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
25-5-17 10:17:17.264 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-625e37e5] ...
25-5-17 10:17:17.264 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:17:17.264 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:17:17.264 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1495707437257) ...
25-5-17 10:17:17.271 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:17:17.276 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1495707437257, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
25-5-17 10:17:17.276 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:17:17.276 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:17:17.276 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707437252, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:17:17.277 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:17:17.279 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707437124] ...
25-5-17 10:17:17.279 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707437124]
25-5-17 10:17:17.279 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:17.280 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:17.280 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@395f60) ...
25-5-17 10:17:17.280 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-31234-client-B' ...
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.280 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.280 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.280 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.280 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.280 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.280 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-31234-client-B' ...
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:17.280 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:17.280 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.280 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.281 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.281 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.281 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.281 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.281 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:17.281 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:17.292 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:17:17.292 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:17:17.300 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:17:17.303 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:17:17.303 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:17:17.309 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:17:17.309 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:17:17.310 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:17:17.310 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
25-5-17 10:17:17.313 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.316 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.319 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.322 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.325 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.328 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.331 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.334 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.336 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
25-5-17 10:17:17.339 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
25-5-17 10:17:17.341 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
25-5-17 10:17:17.344 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:17:17.344 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:17:17.344 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:17:17.347 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:17:17.350 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:17:17.352 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:17:17.355 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:17:17.358 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:17:17.360 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:17:17.360 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
25-5-17 10:17:17.364 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
25-5-17 10:17:17.367 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
25-5-17 10:17:17.370 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
25-5-17 10:17:17.373 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:17:17.373 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
25-5-17 10:17:17.375 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
25-5-17 10:17:17.378 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:17:17.378 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:17:17.378 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
25-5-17 10:17:17.381 | DownOperation   | Test worker    | INFO : 
25-5-17 10:17:17.381 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:17:17.381 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.381 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@1cee0f87) ...
25-5-17 10:17:17.381 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:17.382 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.382 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:17.382 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:17:17.382 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.382 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@1ac6bf62) ...
25-5-17 10:17:17.382 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:17.382 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
25-5-17 10:17:17.382 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@51179000) ...
25-5-17 10:17:17.383 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@77cafa68) ...
25-5-17 10:17:17.383 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707437281] ...
25-5-17 10:17:17.383 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707437281]
25-5-17 10:17:17.383 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707437281] ...
25-5-17 10:17:17.383 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:17:17.383 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-170525101614951-31234-client-B/.syncany/cache/database-A-0000000001
25-5-17 10:17:17.383 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@41af5c1a) ...
25-5-17 10:17:17.384 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:17:17.384 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101614951-31234-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.385 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707437257
25-5-17 10:17:17.386 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101614951-31234-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:17:17.386 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:17:17.386 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1495707437257], B=[]}
25-5-17 10:17:17.386 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:17:17.386 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707437257
25-5-17 10:17:17.386 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:17:17.386 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707437257
25-5-17 10:17:17.386 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:17:17.386 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:17:17.386 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:17:17.386 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
25-5-17 10:17:17.386 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707437257]
25-5-17 10:17:17.386 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:17:17.386 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1495707437257]
25-5-17 10:17:17.387 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:17:17.387 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101614951-31234-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.388 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707437257
25-5-17 10:17:17.388 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:17:17.389 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.389 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:17:17.389 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:17:17.389 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
25-5-17 10:17:17.389 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=symlink-target, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
25-5-17 10:17:17.390 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file symlink-name
25-5-17 10:17:17.390 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=symlink-target, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170525101614951-31234-client-B/symlink-name
25-5-17 10:17:17.390 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=symlink-target, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.390 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
25-5-17 10:17:17.390 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=e94f2a8f0238fa363a27afbdbfc469fc58153411, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
25-5-17 10:17:17.390 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file symlink-target
25-5-17 10:17:17.390 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=e94f2a8f0238fa363a27afbdbfc469fc58153411, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170525101614951-31234-client-B/symlink-target
25-5-17 10:17:17.390 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=e94f2a8f0238fa363a27afbdbfc469fc58153411, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:17:17.391 | DownOperation   | Test worker    | INFO :   + Adding multichunk e607a6da7ea618cb14056fae5285ab3dc93db569 to download list ...
25-5-17 10:17:17.391 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:17:17.391 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@32a0fac6) ...
25-5-17 10:17:17.391 | Downloader      | Test worker    | INFO :   + Downloading multichunk e607a6da7ea618cb14056fae5285ab3dc93db569 ...
25-5-17 10:17:17.391 | Downloader      | Test worker    | INFO :   + Decrypting multichunk e607a6da7ea618cb14056fae5285ab3dc93db569 ...
25-5-17 10:17:17.392 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk e607a6da7ea618cb14056fae5285ab3dc93db569 ...
25-5-17 10:17:17.393 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:17:17.393 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=e94f2a8f0238fa363a27afbdbfc469fc58153411, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:17:17.393 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=symlink-target, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.393 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:17:17.393 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=e94f2a8f0238fa363a27afbdbfc469fc58153411, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
25-5-17 10:17:17.393 | Assembler       | Test worker    | INFO :      - Creating file symlink-target to /tmp/syncanytest/syncany-170525101614951-31234-client-B/.syncany/cache/temp-reconstructedFileVersion-4013195807607726880.tmp ...
25-5-17 10:17:17.394 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
25-5-17 10:17:17.394 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=symlink-target, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.394 | FileSystemActio | Test worker    | INFO :      - Creating symlink at /tmp/syncanytest/syncany-170525101614951-31234-client-B/symlink-name (target: symlink-target) ...
25-5-17 10:17:17.394 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:17:17.395 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
25-5-17 10:17:17.395 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1495707437257, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
25-5-17 10:17:17.401 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707437281] ...
25-5-17 10:17:17.402 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707437281]
25-5-17 10:17:17.402 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:17.402 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:17.402 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@3816bc2b) ...
25-5-17 10:17:17.402 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:17:17.409 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.409 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
25-5-17 10:17:17.419 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.420 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-A' ...
25-5-17 10:17:17.420 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.420 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.420 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.420 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.420 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.420 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.421 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.421 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-A' ...
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:17.421 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.421 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.421 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.421 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.421 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.421 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:17.421 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:17.439 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:17:17.439 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:17:17.456 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:17:17.459 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:17:17.459 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:17:17.465 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:17:17.465 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:17:17.465 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:17:17.465 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
25-5-17 10:17:17.469 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.471 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.474 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.476 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.479 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.481 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.484 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.487 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.489 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
25-5-17 10:17:17.491 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
25-5-17 10:17:17.494 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
25-5-17 10:17:17.497 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:17:17.497 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:17:17.497 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:17:17.500 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:17:17.502 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:17:17.505 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:17:17.507 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:17:17.510 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:17:17.512 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:17:17.512 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
25-5-17 10:17:17.515 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
25-5-17 10:17:17.518 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
25-5-17 10:17:17.521 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
25-5-17 10:17:17.525 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:17:17.525 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
25-5-17 10:17:17.528 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
25-5-17 10:17:17.531 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:17:17.531 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:17:17.531 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
25-5-17 10:17:17.534 | UpOperation     | Test worker    | INFO : 
25-5-17 10:17:17.534 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:17:17.534 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.534 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6f86b0b6) ...
25-5-17 10:17:17.535 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.535 | StatusOperation | Test worker    | INFO : 
25-5-17 10:17:17.535 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:17:17.535 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.535 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:17:17.535 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@654f0e34) ...
25-5-17 10:17:17.535 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101614951-45268-client-A ...
25-5-17 10:17:17.536 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:17:17.536 | StatusOperation | Test worker    | FINE : - New file: folder1
25-5-17 10:17:17.536 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@24bd016d) ...
25-5-17 10:17:17.536 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:17.536 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.536 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:17.536 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:17:17.536 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.536 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@3dd2669c) ...
25-5-17 10:17:17.536 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:17.536 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4955a816) ...
25-5-17 10:17:17.536 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:17:17.536 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707437422] ...
25-5-17 10:17:17.536 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707437422]
25-5-17 10:17:17.537 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707437422] ...
25-5-17 10:17:17.537 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.538 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:17:17.538 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:17:17.538 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@1ffb8141) ...
25-5-17 10:17:17.538 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:17:17.538 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101614951-45268-client-A/folder1
25-5-17 10:17:17.538 | Indexer         | AsyncI/syncany | FINE : - /File: folder1 (directory/symlink/0-byte-file)
25-5-17 10:17:17.539 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: folder1, FOLDER)
25-5-17 10:17:17.539 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file folder1
25-5-17 10:17:17.539 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxr-x, dosAttributes=--a-]
25-5-17 10:17:17.539 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
25-5-17 10:17:17.539 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@7047f1d6) ...
25-5-17 10:17:17.539 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@3460452d) ...
25-5-17 10:17:17.539 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707437538, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.539 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@345c6e4e) ...
25-5-17 10:17:17.539 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:17:17.539 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
25-5-17 10:17:17.540 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:17:17.540 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1495707437540, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.540 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1495707437540 to file /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000001 ... 
25-5-17 10:17:17.540 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.541 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:17:17.541 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
25-5-17 10:17:17.541 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-pcEXQ-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
25-5-17 10:17:17.542 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:17:17.542 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:17:17.543 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:17:17.544 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/temp-transaction-6856796942373635245.tmp
25-5-17 10:17:17.544 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@6457aba6) ...
25-5-17 10:17:17.544 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-3264e0d9] ...
25-5-17 10:17:17.544 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:17:17.544 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@748b3575) ...
25-5-17 10:17:17.544 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-pcEXQ-database-A-0000000001] ...
25-5-17 10:17:17.544 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-pcEXQ-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
25-5-17 10:17:17.545 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-3264e0d9] ...
25-5-17 10:17:17.545 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:17:17.545 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:17:17.545 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1495707437540) ...
25-5-17 10:17:17.546 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:17:17.550 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1495707437540, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.550 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:17:17.550 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:17:17.551 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707437543, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:17:17.551 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:17:17.553 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707437422] ...
25-5-17 10:17:17.554 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707437422]
25-5-17 10:17:17.554 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:17.554 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:17.554 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@cd14626) ...
25-5-17 10:17:17.554 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.554 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-B' ...
25-5-17 10:17:17.554 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.554 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.554 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.554 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.555 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-B' ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.555 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:17.555 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:17.565 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
25-5-17 10:17:17.566 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
25-5-17 10:17:17.574 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
25-5-17 10:17:17.579 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
25-5-17 10:17:17.579 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
25-5-17 10:17:17.585 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
25-5-17 10:17:17.585 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
25-5-17 10:17:17.585 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
25-5-17 10:17:17.585 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
25-5-17 10:17:17.588 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.591 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.593 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.596 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.598 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.601 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.604 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.606 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
25-5-17 10:17:17.609 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
25-5-17 10:17:17.611 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
25-5-17 10:17:17.614 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
25-5-17 10:17:17.616 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
25-5-17 10:17:17.616 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
25-5-17 10:17:17.616 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
25-5-17 10:17:17.619 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
25-5-17 10:17:17.622 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
25-5-17 10:17:17.625 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
25-5-17 10:17:17.627 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
25-5-17 10:17:17.629 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
25-5-17 10:17:17.631 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
25-5-17 10:17:17.631 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
25-5-17 10:17:17.634 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
25-5-17 10:17:17.636 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
25-5-17 10:17:17.643 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
25-5-17 10:17:17.646 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
25-5-17 10:17:17.646 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
25-5-17 10:17:17.649 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
25-5-17 10:17:17.651 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
25-5-17 10:17:17.651 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
25-5-17 10:17:17.652 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
25-5-17 10:17:17.654 | DownOperation   | Test worker    | INFO : 
25-5-17 10:17:17.654 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:17:17.655 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.655 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@2fde4976) ...
25-5-17 10:17:17.655 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:17.655 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.655 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:17.655 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:17:17.655 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.655 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5c296395) ...
25-5-17 10:17:17.656 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:17.656 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
25-5-17 10:17:17.656 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7ea18e29) ...
25-5-17 10:17:17.656 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@1082d08a) ...
25-5-17 10:17:17.656 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707437555] ...
25-5-17 10:17:17.656 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707437555]
25-5-17 10:17:17.656 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707437555] ...
25-5-17 10:17:17.657 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:17:17.657 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-170525101614951-45268-client-B/.syncany/cache/database-A-0000000001
25-5-17 10:17:17.657 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@19314648) ...
25-5-17 10:17:17.657 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:17:17.657 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101614951-45268-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.658 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707437540
25-5-17 10:17:17.659 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101614951-45268-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:17:17.659 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:17:17.659 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1495707437540], B=[]}
25-5-17 10:17:17.659 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:17:17.659 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707437540
25-5-17 10:17:17.659 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:17:17.659 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707437540
25-5-17 10:17:17.659 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:17:17.659 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:17:17.659 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:17:17.659 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
25-5-17 10:17:17.659 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707437540]
25-5-17 10:17:17.659 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:17:17.659 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1495707437540]
25-5-17 10:17:17.659 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:17:17.660 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101614951-45268-client-B/.syncany/cache/database-A-0000000001 ...
25-5-17 10:17:17.661 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1495707437540
25-5-17 10:17:17.661 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:17:17.661 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxr-x, dosAttributes=--a-]
25-5-17 10:17:17.662 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file folder1
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxr-x, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170525101614951-45268-client-B/folder1
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxr-x, dosAttributes=--a-]]
25-5-17 10:17:17.662 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxr-x, dosAttributes=--a-]]
25-5-17 10:17:17.662 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:17:17.662 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxr-x, dosAttributes=--a-]]
25-5-17 10:17:17.662 | FileSystemActio | Test worker    | INFO :      - Creating folder at FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=null, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxr-x, dosAttributes=--a-] ...
25-5-17 10:17:17.663 | FileSystemActio | Test worker    | INFO :      - Creating folder at /tmp/syncanytest/syncany-170525101614951-45268-client-B/folder1 ...
25-5-17 10:17:17.663 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rwxrwxr-x ...
25-5-17 10:17:17.663 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:17:17.663 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
25-5-17 10:17:17.663 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1495707437540, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.670 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707437555] ...
25-5-17 10:17:17.670 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707437555]
25-5-17 10:17:17.670 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:17.671 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:17.671 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@65ccdeb2) ...
25-5-17 10:17:17.671 | DownOperation   | Test worker    | INFO : Sync down done.
25-5-17 10:17:17.672 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.672 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-A' ...
25-5-17 10:17:17.672 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.672 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.672 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.672 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.673 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-A' ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.673 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:17.673 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:17.674 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.674 | UpOperation     | Test worker    | INFO : 
25-5-17 10:17:17.674 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
25-5-17 10:17:17.674 | UpOperation     | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.674 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@30153fd1) ...
25-5-17 10:17:17.675 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.675 | StatusOperation | Test worker    | INFO : 
25-5-17 10:17:17.675 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
25-5-17 10:17:17.675 | StatusOperation | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.675 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
25-5-17 10:17:17.675 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@33f6ea50) ...
25-5-17 10:17:17.675 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170525101614951-45268-client-A ...
25-5-17 10:17:17.675 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
25-5-17 10:17:17.676 | StatusOperation | Test worker    | FINE : - New file: folder1/symlink-name
25-5-17 10:17:17.676 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@6a11e453) ...
25-5-17 10:17:17.676 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:17.676 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.676 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:17.676 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
25-5-17 10:17:17.676 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.676 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@41e96b1d) ...
25-5-17 10:17:17.677 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:17.677 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:17:17.677 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7a632211) ...
25-5-17 10:17:17.677 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
25-5-17 10:17:17.677 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1495707437673] ...
25-5-17 10:17:17.677 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1495707437673]
25-5-17 10:17:17.677 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1495707437673] ...
25-5-17 10:17:17.678 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.678 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
25-5-17 10:17:17.678 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
25-5-17 10:17:17.678 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@3edfe4b) ...
25-5-17 10:17:17.678 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
25-5-17 10:17:17.678 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170525101614951-45268-client-A/folder1/symlink-name
25-5-17 10:17:17.678 | Indexer         | AsyncI/syncany | FINE : - /File: folder1/symlink-name (directory/symlink/0-byte-file)
25-5-17 10:17:17.679 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: folder1/symlink-name, SYMLINK)
25-5-17 10:17:17.679 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file folder1/symlink-name
25-5-17 10:17:17.679 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=/does/not/exist, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
25-5-17 10:17:17.679 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
25-5-17 10:17:17.679 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@2c38e532) ...
25-5-17 10:17:17.679 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@29097e9d) ...
25-5-17 10:17:17.680 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707437678, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.680 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@5ddfafa2) ...
25-5-17 10:17:17.680 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
25-5-17 10:17:17.680 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
25-5-17 10:17:17.680 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
25-5-17 10:17:17.680 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1495707437680, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.681 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1495707437680 to file /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000002 ... 
25-5-17 10:17:17.681 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000002 ...
25-5-17 10:17:17.682 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
25-5-17 10:17:17.682 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
25-5-17 10:17:17.683 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-SIRav-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
25-5-17 10:17:17.683 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
25-5-17 10:17:17.683 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
25-5-17 10:17:17.685 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/temp-transaction-6720736520501900343.tmp
25-5-17 10:17:17.685 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@407b01d0) ...
25-5-17 10:17:17.685 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-1e3f1e9d] ...
25-5-17 10:17:17.685 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
25-5-17 10:17:17.685 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@45612b61) ...
25-5-17 10:17:17.685 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170525101614951-45268-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-SIRav-database-A-0000000002] ...
25-5-17 10:17:17.686 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-SIRav-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
25-5-17 10:17:17.686 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-1e3f1e9d] ...
25-5-17 10:17:17.686 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
25-5-17 10:17:17.686 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
25-5-17 10:17:17.686 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1495707437680) ...
25-5-17 10:17:17.686 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
25-5-17 10:17:17.690 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
25-5-17 10:17:17.693 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1495707437680, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.693 | UpOperation     | Test worker    | INFO : Committing local database.
25-5-17 10:17:17.693 | UpOperation     | Test worker    | FINE : Waiting for new database version.
25-5-17 10:17:17.693 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1495707437690, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
25-5-17 10:17:17.693 | UpOperation     | Test worker    | INFO : Sync up done.
25-5-17 10:17:17.696 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1495707437673] ...
25-5-17 10:17:17.696 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1495707437673]
25-5-17 10:17:17.696 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:17.696 | Cache           | Test worker    | INFO : Cache size okay (1 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:17.697 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@2c2e84e7) ...
25-5-17 10:17:17.697 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.697 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-B' ...
25-5-17 10:17:17.697 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.697 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.697 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.697 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.697 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.697 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.697 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.697 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.697 | org.syncany.plu | Test worker    | FINE : Validating required fields
25-5-17 10:17:17.697 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170525101614951-45268-client-B' ...
25-5-17 10:17:17.698 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
25-5-17 10:17:17.698 | TransferManager | Test worker    | INFO : - With feature Retriable
25-5-17 10:17:17.698 | TransferManager | Test worker    | INFO : - With feature PathAware
25-5-17 10:17:17.698 | TransferManager | Test worker    | INFO : - With feature TransactionAware
25-5-17 10:17:17.698 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
25-5-17 10:17:17.698 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
25-5-17 10:17:17.698 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
25-5-17 10:17:17.698 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
25-5-17 10:17:17.698 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
25-5-17 10:17:17.698 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
25-5-17 10:17:17.698 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
25-5-17 10:17:17.698 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
25-5-17 10:17:17.699 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.699 | DownOperation   | Test worker    | INFO : 
25-5-17 10:17:17.699 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
25-5-17 10:17:17.699 | DownOperation   | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.699 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@112a8872) ...
25-5-17 10:17:17.699 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
25-5-17 10:17:17.699 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.699 | LsRemoteOperati | Test worker    | INFO : 
25-5-17 10:17:17.699 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
25-5-17 10:17:17.700 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
25-5-17 10:17:17.700 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@24761bd9) ...
25-5-17 10:17:17.700 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
25-5-17 10:17:17.700 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
25-5-17 10:17:17.700 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
25-5-17 10:17:17.700 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1395320a) ...
25-5-17 10:17:17.700 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@527b8e7f) ...
25-5-17 10:17:17.700 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1495707437698] ...
25-5-17 10:17:17.700 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1495707437698]
25-5-17 10:17:17.700 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1495707437698] ...
25-5-17 10:17:17.701 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
25-5-17 10:17:17.701 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-170525101614951-45268-client-B/.syncany/cache/database-A-0000000002
25-5-17 10:17:17.701 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@60900e09) ...
25-5-17 10:17:17.701 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
25-5-17 10:17:17.701 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170525101614951-45268-client-B/.syncany/cache/database-A-0000000002 ...
25-5-17 10:17:17.703 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1495707437680
25-5-17 10:17:17.704 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101614951-45268-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
25-5-17 10:17:17.704 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170525101614951-45268-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
25-5-17 10:17:17.704 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
25-5-17 10:17:17.704 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A2)/T=1495707437680], B=[A/(A1)/T=1495707437540]}
25-5-17 10:17:17.704 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
25-5-17 10:17:17.704 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1495707437540
25-5-17 10:17:17.704 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1495707437680
25-5-17 10:17:17.705 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
25-5-17 10:17:17.705 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1495707437540
25-5-17 10:17:17.705 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1495707437680
25-5-17 10:17:17.705 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
25-5-17 10:17:17.705 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
25-5-17 10:17:17.705 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
25-5-17 10:17:17.705 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1495707437540]
25-5-17 10:17:17.705 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1495707437540, A/(A2)/T=1495707437680]
25-5-17 10:17:17.705 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
25-5-17 10:17:17.705 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A2)/T=1495707437680]
25-5-17 10:17:17.705 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
25-5-17 10:17:17.705 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170525101614951-45268-client-B/.syncany/cache/database-A-0000000002 ...
25-5-17 10:17:17.707 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1495707437680
25-5-17 10:17:17.707 | DownOperation   | Test worker    | INFO : Determine file system actions ...
25-5-17 10:17:17.708 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=/does/not/exist, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
25-5-17 10:17:17.709 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file folder1/symlink-name
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=/does/not/exist, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170525101614951-45268-client-B/folder1/symlink-name
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=/does/not/exist, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.709 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO :    Sorted actions:
25-5-17 10:17:17.709 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=/does/not/exist, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.709 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
25-5-17 10:17:17.709 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Thu May 25 10:17:17 UTC 2017, linkTarget=/does/not/exist, checksum=null, updated=Thu May 25 10:17:17 UTC 2017, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
25-5-17 10:17:17.710 | FileSystemActio | Test worker    | INFO :      - Parent folder does not exist, creating /tmp/syncanytest/syncany-170525101614951-45268-client-B/folder1 ...
25-5-17 10:17:17.710 | FileSystemActio | Test worker    | INFO :      - Creating symlink at /tmp/syncanytest/syncany-170525101614951-45268-client-B/folder1/symlink-name (target: /does/not/exist) ...
25-5-17 10:17:17.710 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
25-5-17 10:17:17.710 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
25-5-17 10:17:17.710 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1495707437680, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
25-5-17 10:17:17.722 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1495707437698] ...
25-5-17 10:17:17.723 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1495707437698]
25-5-17 10:17:17.723 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
25-5-17 10:17:17.723 | Cache           | Test worker    | INFO : Cache size okay (1 KB), no need to clean (keep size is 500 MB)
25-5-17 10:17:17.723 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@4da914f2) ...
25-5-17 10:17:17.723 | DownOperation   | Test worker    | INFO : Sync down done.