2020-10-09 19:35:46 +02:00
import Logger from './Logger' ;
2021-12-13 11:32:22 +02:00
import LockHandler , { appTypeToLockType , hasActiveLock , LockClientType , LockType } from './services/synchronizer/LockHandler' ;
2021-11-03 14:26:26 +02:00
import Setting , { AppType } from './models/Setting' ;
2020-11-05 18:58:23 +02:00
import shim from './shim' ;
import MigrationHandler from './services/synchronizer/MigrationHandler' ;
import eventManager from './eventManager' ;
import { _ } from './locale' ;
2021-01-22 19:41:11 +02:00
import BaseItem from './models/BaseItem' ;
import Folder from './models/Folder' ;
import Note from './models/Note' ;
import Resource from './models/Resource' ;
import ItemChange from './models/ItemChange' ;
import ResourceLocalState from './models/ResourceLocalState' ;
import MasterKey from './models/MasterKey' ;
2021-08-12 17:54:10 +02:00
import BaseModel , { ModelType } from './BaseModel' ;
2021-01-22 19:41:11 +02:00
import time from './time' ;
2021-01-29 20:45:11 +02:00
import ResourceService from './services/ResourceService' ;
2021-08-23 19:47:07 +02:00
import EncryptionService from './services/e2ee/EncryptionService' ;
2021-05-13 18:57:37 +02:00
import JoplinError from './JoplinError' ;
import ShareService from './services/share/ShareService' ;
2021-06-17 13:39:06 +02:00
import TaskQueue from './TaskQueue' ;
2021-06-18 18:17:25 +02:00
import ItemUploader from './services/synchronizer/ItemUploader' ;
2021-10-15 13:38:14 +02:00
import { FileApi , RemoteItem } from './file-api' ;
2021-08-07 13:22:37 +02:00
import JoplinDatabase from './JoplinDatabase' ;
2022-04-13 13:18:38 +02:00
import { fetchSyncInfo , getActiveMasterKey , localSyncInfo , mergeSyncInfos , saveLocalSyncInfo , setMasterKeyHasBeenUsed , SyncInfo , syncInfoEquals , uploadSyncInfo } from './services/synchronizer/syncInfoUtils' ;
2021-10-03 17:00:49 +02:00
import { getMasterPassword , setupAndDisableEncryption , setupAndEnableEncryption } from './services/e2ee/utils' ;
import { generateKeyPair } from './services/e2ee/ppk' ;
2021-10-15 13:24:22 +02:00
import syncDebugLog from './services/synchronizer/syncDebugLog' ;
2021-05-13 18:57:37 +02:00
const { sprintf } = require ( 'sprintf-js' ) ;
2020-11-05 18:58:23 +02:00
const { Dirnames } = require ( './services/synchronizer/utils/types' ) ;
2017-05-18 21:58:01 +02:00
2021-08-07 13:22:37 +02:00
const logger = Logger . create ( 'Synchronizer' ) ;
2021-05-15 20:56:49 +02:00
function isCannotSyncError ( error : any ) : boolean {
if ( ! error ) return false ;
if ( [ 'rejectedByTarget' , 'fileNotFound' ] . indexOf ( error . code ) >= 0 ) return true ;
// If the request times out we give up too because sometimes it's due to the
// file being large or some other connection issues, and we don't want that
// file to block the sync process. The user can choose to retry later on.
//
// message: "network timeout at: .....
// name: "FetchError"
// type: "request-timeout"
if ( error . type === 'request-timeout' || error . message . includes ( 'network timeout' ) ) return true ;
return false ;
}
2020-10-09 19:35:46 +02:00
export default class Synchronizer {
2021-06-16 11:43:39 +02:00
public static verboseMode : boolean = true ;
2021-08-07 13:22:37 +02:00
private db_ : JoplinDatabase ;
2021-06-19 11:34:44 +02:00
private api_ : FileApi ;
2021-12-13 11:32:22 +02:00
private appType_ : AppType ;
2020-11-12 21:13:28 +02:00
private logger_ : Logger = new Logger ( ) ;
private state_ : string = 'idle' ;
private cancelling_ : boolean = false ;
2021-08-12 17:54:10 +02:00
public maxResourceSize_ : number = null ;
2020-11-12 21:13:28 +02:00
private downloadQueue_ : any = null ;
private clientId_ : string ;
private lockHandler_ : LockHandler ;
private migrationHandler_ : MigrationHandler ;
2021-01-29 20:45:11 +02:00
private encryptionService_ : EncryptionService = null ;
private resourceService_ : ResourceService = null ;
2020-11-12 21:13:28 +02:00
private syncTargetIsLocked_ : boolean = false ;
2021-05-13 18:57:37 +02:00
private shareService_ : ShareService = null ;
2021-11-03 14:26:26 +02:00
private lockClientType_ : LockClientType = null ;
2020-10-09 19:35:46 +02:00
// Debug flags are used to test certain hard-to-test conditions
// such as cancelling in the middle of a loop.
2020-11-12 21:13:28 +02:00
public testingHooks_ : string [ ] = [ ] ;
2020-10-09 19:35:46 +02:00
2020-11-12 21:13:28 +02:00
private onProgress_ : Function ;
private progressReport_ : any = { } ;
2020-10-09 19:35:46 +02:00
2020-11-12 21:13:28 +02:00
public dispatch : Function ;
2020-10-09 19:35:46 +02:00
2021-12-13 11:32:22 +02:00
public constructor ( db : JoplinDatabase , api : FileApi , appType : AppType ) {
2017-05-19 21:12:09 +02:00
this . db_ = db ;
this . api_ = api ;
2017-07-07 00:15:31 +02:00
this . appType_ = appType ;
2019-10-11 01:03:23 +02:00
this . clientId_ = Setting . value ( 'clientId' ) ;
2017-07-14 21:06:01 +02:00
2019-07-30 09:35:42 +02:00
this . onProgress_ = function ( ) { } ;
2017-07-14 21:06:01 +02:00
this . progressReport_ = { } ;
2017-07-16 23:17:22 +02:00
2019-07-30 09:35:42 +02:00
this . dispatch = function ( ) { } ;
2021-06-18 18:17:25 +02:00
this . apiCall = this . apiCall . bind ( this ) ;
2017-05-18 21:58:01 +02:00
}
2017-06-24 19:40:03 +02:00
state() {
return this . state_ ;
}
2017-05-18 21:58:01 +02:00
db() {
2017-05-19 21:12:09 +02:00
return this . db_ ;
2017-05-18 21:58:01 +02:00
}
api() {
2017-05-19 21:12:09 +02:00
return this . api_ ;
2017-05-18 21:58:01 +02:00
}
2019-10-11 01:03:23 +02:00
clientId() {
return this . clientId_ ;
}
2020-11-12 21:13:28 +02:00
setLogger ( l : Logger ) {
2017-06-23 23:32:24 +02:00
this . logger_ = l ;
}
logger() {
return this . logger_ ;
}
2020-08-02 13:28:50 +02:00
lockHandler() {
if ( this . lockHandler_ ) return this . lockHandler_ ;
this . lockHandler_ = new LockHandler ( this . api ( ) ) ;
return this . lockHandler_ ;
}
2021-11-03 14:26:26 +02:00
private lockClientType ( ) : LockClientType {
if ( this . lockClientType_ ) return this . lockClientType_ ;
2021-12-13 11:32:22 +02:00
this . lockClientType_ = appTypeToLockType ( this . appType_ ) ;
2021-11-03 14:26:26 +02:00
return this . lockClientType_ ;
}
2020-08-02 13:28:50 +02:00
migrationHandler() {
if ( this . migrationHandler_ ) return this . migrationHandler_ ;
2021-11-03 14:26:26 +02:00
this . migrationHandler_ = new MigrationHandler ( this . api ( ) , this . db ( ) , this . lockHandler ( ) , this . lockClientType ( ) , this . clientId_ ) ;
2020-08-02 13:28:50 +02:00
return this . migrationHandler_ ;
}
2019-05-12 02:15:52 +02:00
maxResourceSize() {
if ( this . maxResourceSize_ !== null ) return this . maxResourceSize_ ;
2021-12-13 11:32:22 +02:00
return this . appType_ === AppType . Mobile ? 100 * 1000 * 1000 : Infinity ;
2019-05-12 02:15:52 +02:00
}
2021-05-13 18:57:37 +02:00
public setShareService ( v : ShareService ) {
this . shareService_ = v ;
}
2021-01-29 20:45:11 +02:00
public setEncryptionService ( v : any ) {
2017-12-14 21:39:13 +02:00
this . encryptionService_ = v ;
}
2019-07-30 09:35:42 +02:00
encryptionService() {
2017-12-14 21:39:13 +02:00
return this . encryptionService_ ;
}
2021-01-29 20:45:11 +02:00
public setResourceService ( v : ResourceService ) {
this . resourceService_ = v ;
}
protected resourceService ( ) : ResourceService {
return this . resourceService_ ;
}
2019-12-13 03:16:34 +02:00
async waitForSyncToFinish() {
if ( this . state ( ) === 'idle' ) return ;
while ( true ) {
await time . sleep ( 1 ) ;
if ( this . state ( ) === 'idle' ) return ;
}
}
2020-12-08 21:03:22 +02:00
private static reportHasErrors ( report : any ) : boolean {
return ! ! report && ! ! report . errors && ! ! report . errors . length ;
}
2021-11-03 14:26:26 +02:00
private static completionTime ( report : any ) : string {
const duration = report . completedTime - report . startTime ;
if ( duration > 1000 ) return ` ${ Math . round ( duration / 1000 ) } s ` ;
return ` ${ duration } ms ` ;
}
2020-11-12 21:13:28 +02:00
static reportToLines ( report : any ) {
2020-03-14 01:46:14 +02:00
const lines = [ ] ;
2019-07-29 15:43:53 +02:00
if ( report . createLocal ) lines . push ( _ ( 'Created local items: %d.' , report . createLocal ) ) ;
if ( report . updateLocal ) lines . push ( _ ( 'Updated local items: %d.' , report . updateLocal ) ) ;
if ( report . createRemote ) lines . push ( _ ( 'Created remote items: %d.' , report . createRemote ) ) ;
if ( report . updateRemote ) lines . push ( _ ( 'Updated remote items: %d.' , report . updateRemote ) ) ;
if ( report . deleteLocal ) lines . push ( _ ( 'Deleted local items: %d.' , report . deleteLocal ) ) ;
if ( report . deleteRemote ) lines . push ( _ ( 'Deleted remote items: %d.' , report . deleteRemote ) ) ;
if ( report . fetchingTotal && report . fetchingProcessed ) lines . push ( _ ( 'Fetched items: %d/%d.' , report . fetchingProcessed , report . fetchingTotal ) ) ;
if ( report . cancelling && ! report . completedTime ) lines . push ( _ ( 'Cancelling...' ) ) ;
2021-11-03 14:26:26 +02:00
if ( report . completedTime ) lines . push ( _ ( 'Completed: %s (%s)' , time . formatMsToLocal ( report . completedTime ) , this . completionTime ( report ) ) ) ;
2020-12-08 21:03:22 +02:00
if ( this . reportHasErrors ( report ) ) lines . push ( _ ( 'Last error: %s' , report . errors [ report . errors . length - 1 ] . toString ( ) . substr ( 0 , 500 ) ) ) ;
2017-07-18 00:43:29 +02:00
2017-07-14 21:06:01 +02:00
return lines ;
}
2021-10-15 13:24:22 +02:00
logSyncOperation ( action : string , local : any = null , remote : RemoteItem = null , message : string = null , actionCount : number = 1 ) {
2020-03-14 01:46:14 +02:00
const line = [ 'Sync' ] ;
2017-06-24 19:40:03 +02:00
line . push ( action ) ;
2017-07-14 21:06:01 +02:00
if ( message ) line . push ( message ) ;
2017-06-24 19:40:03 +02:00
2017-07-14 20:02:45 +02:00
let type = local && local . type_ ? local.type_ : null ;
if ( ! type ) type = remote && remote . type_ ? remote.type_ : null ;
if ( type ) line . push ( BaseItem . modelTypeToClassName ( type ) ) ;
2017-06-24 19:40:03 +02:00
if ( local ) {
2020-03-14 01:46:14 +02:00
const s = [ ] ;
2017-06-24 19:40:03 +02:00
s . push ( local . id ) ;
2019-09-19 23:51:18 +02:00
line . push ( ` (Local ${ s . join ( ', ' ) } ) ` ) ;
2017-06-24 19:40:03 +02:00
}
if ( remote ) {
2020-03-14 01:46:14 +02:00
const s = [ ] ;
2017-07-16 12:17:40 +02:00
s . push ( remote . id ? remote.id : remote.path ) ;
2019-09-19 23:51:18 +02:00
line . push ( ` (Remote ${ s . join ( ', ' ) } ) ` ) ;
2017-06-24 19:40:03 +02:00
}
2021-06-16 11:43:39 +02:00
if ( Synchronizer . verboseMode ) {
2021-08-07 13:22:37 +02:00
logger . info ( line . join ( ': ' ) ) ;
2021-06-16 11:43:39 +02:00
} else {
2021-08-07 13:22:37 +02:00
logger . debug ( line . join ( ': ' ) ) ;
2021-06-16 11:43:39 +02:00
}
2017-07-14 21:06:01 +02:00
2021-10-15 13:24:22 +02:00
if ( ! [ 'fetchingProcessed' , 'fetchingTotal' ] . includes ( action ) ) syncDebugLog . info ( line . join ( ': ' ) ) ;
2017-07-14 21:06:01 +02:00
if ( ! this . progressReport_ [ action ] ) this . progressReport_ [ action ] = 0 ;
2018-01-08 22:36:00 +02:00
this . progressReport_ [ action ] += actionCount ;
2017-07-14 21:06:01 +02:00
this . progressReport_ . state = this . state ( ) ;
this . onProgress_ ( this . progressReport_ ) ;
2017-07-16 23:17:22 +02:00
2020-10-09 19:35:46 +02:00
// Make sure we only send a **copy** of the report since it
// is mutated within this class. Should probably use a lib
// for this but for now this simple fix will do.
2020-11-12 21:13:28 +02:00
const reportCopy : any = { } ;
2020-10-09 19:35:46 +02:00
for ( const n in this . progressReport_ ) reportCopy [ n ] = this . progressReport_ [ n ] ;
if ( reportCopy . errors ) reportCopy . errors = this . progressReport_ . errors . slice ( ) ;
this . dispatch ( { type : 'SYNC_REPORT_UPDATE' , report : reportCopy } ) ;
2017-06-24 19:40:03 +02:00
}
2020-11-12 21:13:28 +02:00
async logSyncSummary ( report : any ) {
2021-08-07 13:22:37 +02:00
logger . info ( 'Operations completed: ' ) ;
2020-03-14 01:46:14 +02:00
for ( const n in report ) {
2017-07-01 00:53:22 +02:00
if ( ! report . hasOwnProperty ( n ) ) continue ;
2018-03-09 22:59:12 +02:00
if ( n == 'errors' ) continue ;
if ( n == 'starting' ) continue ;
if ( n == 'finished' ) continue ;
if ( n == 'state' ) continue ;
2021-06-17 12:21:37 +02:00
if ( n == 'startTime' ) continue ;
2018-03-09 22:59:12 +02:00
if ( n == 'completedTime' ) continue ;
2021-08-07 13:22:37 +02:00
logger . info ( ` ${ n } : ${ report [ n ] ? report [ n ] : '-' } ` ) ;
2017-06-24 19:40:03 +02:00
}
2020-03-14 01:46:14 +02:00
const folderCount = await Folder . count ( ) ;
const noteCount = await Note . count ( ) ;
const resourceCount = await Resource . count ( ) ;
2021-08-07 13:22:37 +02:00
logger . info ( ` Total folders: ${ folderCount } ` ) ;
logger . info ( ` Total notes: ${ noteCount } ` ) ;
logger . info ( ` Total resources: ${ resourceCount } ` ) ;
2017-07-10 01:20:38 +02:00
2020-12-08 21:03:22 +02:00
if ( Synchronizer . reportHasErrors ( report ) ) {
2021-08-07 13:22:37 +02:00
logger . warn ( 'There was some errors:' ) ;
2017-07-10 01:20:38 +02:00
for ( let i = 0 ; i < report . errors . length ; i ++ ) {
2020-03-14 01:46:14 +02:00
const e = report . errors [ i ] ;
2021-08-07 13:22:37 +02:00
logger . warn ( e ) ;
2017-07-10 01:20:38 +02:00
}
}
2017-06-23 20:51:02 +02:00
}
2017-10-14 20:03:23 +02:00
async cancel() {
2018-03-09 22:59:12 +02:00
if ( this . cancelling_ || this . state ( ) == 'idle' ) return ;
2018-08-01 23:05:09 +02:00
2019-06-08 00:20:08 +02:00
// Stop queue but don't set it to null as it may be used to
// retrieve the last few downloads.
2019-06-14 09:11:15 +02:00
if ( this . downloadQueue_ ) this . downloadQueue_ . stop ( ) ;
2019-06-08 00:20:08 +02:00
2018-03-09 22:59:12 +02:00
this . logSyncOperation ( 'cancelling' , null , null , '' ) ;
2017-07-09 17:47:05 +02:00
this . cancelling_ = true ;
2017-10-14 20:03:23 +02:00
2019-09-13 00:16:42 +02:00
return new Promise ( ( resolve ) = > {
2020-10-09 19:35:46 +02:00
const iid = shim . setInterval ( ( ) = > {
2018-03-09 22:59:12 +02:00
if ( this . state ( ) == 'idle' ) {
2020-10-09 19:35:46 +02:00
shim . clearInterval ( iid ) ;
2021-01-29 20:45:11 +02:00
resolve ( null ) ;
2017-10-14 20:03:23 +02:00
}
} , 100 ) ;
} ) ;
2017-07-09 17:47:05 +02:00
}
cancelling() {
return this . cancelling_ ;
}
2019-09-25 20:58:15 +02:00
logLastRequests() {
const lastRequests = this . api ( ) . lastRequests ( ) ;
if ( ! lastRequests || ! lastRequests . length ) return ;
for ( const r of lastRequests ) {
const timestamp = time . unixMsToLocalHms ( r . timestamp ) ;
2021-08-07 13:22:37 +02:00
logger . info ( ` Req ${ timestamp } : ${ r . request } ` ) ;
logger . info ( ` Res ${ timestamp } : ${ r . response } ` ) ;
2019-09-25 20:58:15 +02:00
}
}
2020-11-12 21:13:28 +02:00
static stateToLabel ( state : string ) {
2019-07-29 15:43:53 +02:00
if ( state === 'idle' ) return _ ( 'Idle' ) ;
if ( state === 'in_progress' ) return _ ( 'In progress' ) ;
2018-03-09 21:51:01 +02:00
return state ;
}
2020-11-12 21:13:28 +02:00
isFullSync ( steps : string [ ] ) {
2020-08-02 13:28:50 +02:00
return steps . includes ( 'update_remote' ) && steps . includes ( 'delete_remote' ) && steps . includes ( 'delta' ) ;
2019-10-11 01:03:23 +02:00
}
2020-08-02 13:28:50 +02:00
async lockErrorStatus_() {
2021-11-03 14:26:26 +02:00
const locks = await this . lockHandler ( ) . locks ( ) ;
const currentDate = await this . lockHandler ( ) . currentDate ( ) ;
const hasActiveExclusiveLock = await hasActiveLock ( locks , currentDate , this . lockHandler ( ) . lockTtl , LockType . Exclusive ) ;
2020-08-02 13:28:50 +02:00
if ( hasActiveExclusiveLock ) return 'hasExclusiveLock' ;
2019-10-11 01:03:23 +02:00
2021-11-03 14:26:26 +02:00
const hasActiveSyncLock = await hasActiveLock ( locks , currentDate , this . lockHandler ( ) . lockTtl , LockType . Sync , this . lockClientType ( ) , this . clientId_ ) ;
2020-08-02 13:28:50 +02:00
if ( ! hasActiveSyncLock ) return 'syncLockGone' ;
2019-10-11 01:03:23 +02:00
2020-08-02 13:28:50 +02:00
return '' ;
2019-10-11 01:03:23 +02:00
}
2021-10-03 17:00:49 +02:00
private async setPpkIfNotExist ( localInfo : SyncInfo , remoteInfo : SyncInfo ) {
if ( localInfo . ppk || remoteInfo . ppk ) return localInfo ;
const password = getMasterPassword ( false ) ;
if ( ! password ) return localInfo ;
localInfo . ppk = await generateKeyPair ( this . encryptionService ( ) , password ) ;
return localInfo ;
}
2021-06-18 18:17:25 +02:00
private async apiCall ( fnName : string , . . . args : any [ ] ) {
2020-08-02 13:28:50 +02:00
if ( this . syncTargetIsLocked_ ) throw new JoplinError ( 'Sync target is locked - aborting API call' , 'lockError' ) ;
2020-07-12 17:38:54 +02:00
2020-08-02 13:28:50 +02:00
try {
2021-06-19 11:34:44 +02:00
const output = await ( this . api ( ) as any ) [ fnName ] ( . . . args ) ;
2020-08-02 13:28:50 +02:00
return output ;
} catch ( error ) {
const lockStatus = await this . lockErrorStatus_ ( ) ;
// When there's an error due to a lock, we re-wrap the error and change the error code so that error handling
// does not do special processing on the original error. For example, if a resource could not be downloaded,
// don't mark it as a "cannotSyncItem" since we don't know that.
if ( lockStatus ) {
throw new JoplinError ( ` Sync target lock error: ${ lockStatus } . Original error was: ${ error . message } ` , 'lockError' ) ;
2020-07-12 17:38:54 +02:00
} else {
2020-08-02 13:28:50 +02:00
throw error ;
2020-07-12 17:38:54 +02:00
}
2020-07-11 00:42:03 +02:00
}
2020-07-12 17:38:54 +02:00
}
2020-07-11 00:42:03 +02:00
2018-03-09 21:07:38 +02:00
// Synchronisation is done in three major steps:
//
// 1. UPLOAD: Send to the sync target the items that have changed since the last sync.
// 2. DELETE_REMOTE: Delete on the sync target, the items that have been deleted locally.
// 3. DELTA: Find on the sync target the items that have been modified or deleted and apply the changes locally.
2021-05-03 12:55:38 +02:00
public async start ( options : any = null ) {
2017-06-30 19:54:01 +02:00
if ( ! options ) options = { } ;
2017-07-24 21:47:01 +02:00
2018-03-09 22:59:12 +02:00
if ( this . state ( ) != 'idle' ) {
2020-11-12 21:13:28 +02:00
const error : any = new Error ( sprintf ( 'Synchronisation is already in progress. State: %s' , this . state ( ) ) ) ;
2018-03-09 22:59:12 +02:00
error . code = 'alreadyStarted' ;
2017-07-24 21:47:01 +02:00
throw error ;
2017-07-30 21:51:18 +02:00
}
2018-03-09 22:59:12 +02:00
this . state_ = 'in_progress' ;
2017-07-24 21:47:01 +02:00
2019-07-30 09:35:42 +02:00
this . onProgress_ = options . onProgress ? options.onProgress : function ( ) { } ;
2017-07-14 21:06:01 +02:00
this . progressReport_ = { errors : [ ] } ;
2017-06-30 19:54:01 +02:00
2017-07-18 22:03:07 +02:00
const lastContext = options . context ? options . context : { } ;
2017-07-18 21:57:49 +02:00
2019-07-29 15:43:53 +02:00
const syncSteps = options . syncSteps ? options . syncSteps : [ 'update_remote' , 'delete_remote' , 'delta' ] ;
2018-03-09 21:07:38 +02:00
2019-10-10 23:23:11 +02:00
// The default is to log errors, but when testing it's convenient to be able to catch and verify errors
const throwOnError = options . throwOnError === true ;
2017-07-24 20:58:11 +02:00
const syncTargetId = this . api ( ) . syncTargetId ( ) ;
2017-07-16 14:53:59 +02:00
2020-08-02 13:28:50 +02:00
this . syncTargetIsLocked_ = false ;
2017-07-09 17:47:05 +02:00
this . cancelling_ = false ;
2017-07-02 12:34:07 +02:00
2021-08-12 17:54:10 +02:00
// const masterKeysBefore = await MasterKey.count();
// let hasAutoEnabledEncryption = false;
2017-12-14 21:39:13 +02:00
2020-03-14 01:46:14 +02:00
const synchronizationId = time . unixMs ( ) . toString ( ) ;
2017-06-24 19:40:03 +02:00
2020-03-14 01:46:14 +02:00
const outputContext = Object . assign ( { } , lastContext ) ;
2017-01-29 20:29:34 +02:00
2021-06-17 12:21:37 +02:00
this . progressReport_ . startTime = time . unixMs ( ) ;
2018-03-09 22:59:12 +02:00
this . dispatch ( { type : 'SYNC_STARTED' } ) ;
2020-12-08 21:03:22 +02:00
eventManager . emit ( 'syncStart' ) ;
2017-07-18 00:43:29 +02:00
2021-06-19 15:22:53 +02:00
this . logSyncOperation ( 'starting' , null , null , ` Starting synchronisation to target ${ syncTargetId } ... supportsAccurateTimestamp = ${ this . api ( ) . supportsAccurateTimestamp } ; supportsMultiPut = ${ this . api ( ) . supportsMultiPut } [ ${ synchronizationId } ] ` ) ;
2017-06-23 23:32:24 +02:00
2020-11-12 21:13:28 +02:00
const handleCannotSyncItem = async ( ItemClass : any , syncTargetId : any , item : any , cannotSyncReason : string , itemLocation : any = null ) = > {
2019-05-12 02:15:52 +02:00
await ItemClass . saveSyncDisabled ( syncTargetId , item , cannotSyncReason , itemLocation ) ;
2019-07-29 15:43:53 +02:00
this . dispatch ( { type : 'SYNC_HAS_DISABLED_SYNC_ITEMS' } ) ;
} ;
2019-05-12 02:15:52 +02:00
2020-11-12 21:13:28 +02:00
const resourceRemotePath = ( resourceId : string ) = > {
2020-08-02 13:28:50 +02:00
return ` ${ Dirnames . Resources } / ${ resourceId } ` ;
2019-07-29 15:43:53 +02:00
} ;
2019-07-13 16:57:53 +02:00
2021-10-05 18:47:38 +02:00
// We index resources before sync mostly to flag any potential orphan
// resource before it is being synced. That way, it can potentially be
// auto-deleted at a later time. Indexing resources is fast so it's fine
// to call it every time here.
//
// https://github.com/laurent22/joplin/issues/932#issuecomment-933736405
2021-01-29 20:45:11 +02:00
try {
if ( this . resourceService ( ) ) {
2021-08-07 13:22:37 +02:00
logger . info ( 'Indexing resources...' ) ;
2021-01-29 20:45:11 +02:00
await this . resourceService ( ) . indexNoteResources ( ) ;
}
} catch ( error ) {
2021-08-07 13:22:37 +02:00
logger . error ( 'Error indexing resources:' , error ) ;
2021-01-29 20:45:11 +02:00
}
2021-05-13 18:57:37 +02:00
// Before synchronising make sure all share_id properties are set
// correctly so as to share/unshare the right items.
2021-11-28 18:46:10 +02:00
await Folder . updateAllShareIds ( this . resourceService ( ) ) ;
2021-12-20 16:47:50 +02:00
if ( this . shareService_ ) await this . shareService_ . checkShareConsistency ( ) ;
2021-05-13 18:57:37 +02:00
2021-06-18 18:17:25 +02:00
const itemUploader = new ItemUploader ( this . api ( ) , this . apiCall ) ;
2019-10-10 23:23:11 +02:00
let errorToThrow = null ;
2020-08-02 13:28:50 +02:00
let syncLock = null ;
2019-10-10 23:23:11 +02:00
2017-06-29 20:03:16 +02:00
try {
2020-12-28 13:48:47 +02:00
await this . api ( ) . initialize ( ) ;
2020-09-12 00:33:34 +02:00
this . api ( ) . setTempDirName ( Dirnames . Temp ) ;
2020-08-02 13:28:50 +02:00
try {
2021-10-03 17:00:49 +02:00
let remoteInfo = await fetchSyncInfo ( this . api ( ) ) ;
2021-08-12 17:54:10 +02:00
logger . info ( 'Sync target remote info:' , remoteInfo ) ;
2017-06-29 20:03:16 +02:00
2022-04-13 13:18:38 +02:00
let syncTargetIsNew = false ;
2021-08-12 17:54:10 +02:00
if ( ! remoteInfo . version ) {
2021-08-07 13:22:37 +02:00
logger . info ( 'Sync target is new - setting it up...' ) ;
2020-08-02 13:28:50 +02:00
await this . migrationHandler ( ) . upgrade ( Setting . value ( 'syncVersion' ) ) ;
2021-10-03 17:00:49 +02:00
remoteInfo = await fetchSyncInfo ( this . api ( ) ) ;
2022-04-13 13:18:38 +02:00
syncTargetIsNew = true ;
2021-10-03 17:00:49 +02:00
}
logger . info ( 'Sync target is already setup - checking it...' ) ;
2021-08-12 17:54:10 +02:00
2021-10-03 17:00:49 +02:00
await this . migrationHandler ( ) . checkCanSync ( remoteInfo ) ;
2021-08-12 17:54:10 +02:00
2021-10-03 17:00:49 +02:00
let localInfo = await localSyncInfo ( ) ;
2021-08-12 17:54:10 +02:00
2021-10-03 17:00:49 +02:00
logger . info ( 'Sync target local info:' , localInfo ) ;
2021-08-12 17:54:10 +02:00
2021-10-03 17:00:49 +02:00
localInfo = await this . setPpkIfNotExist ( localInfo , remoteInfo ) ;
2021-08-12 17:54:10 +02:00
2022-04-13 13:18:38 +02:00
if ( syncTargetIsNew && localInfo . activeMasterKeyId ) {
localInfo = setMasterKeyHasBeenUsed ( localInfo , localInfo . activeMasterKeyId ) ;
}
2021-10-03 17:00:49 +02:00
// console.info('LOCAL', localInfo);
// console.info('REMOTE', remoteInfo);
2021-08-12 17:54:10 +02:00
2021-10-03 17:00:49 +02:00
if ( ! syncInfoEquals ( localInfo , remoteInfo ) ) {
2022-04-13 13:18:38 +02:00
let newInfo = mergeSyncInfos ( localInfo , remoteInfo ) ;
if ( newInfo . activeMasterKeyId ) newInfo = setMasterKeyHasBeenUsed ( newInfo , newInfo . activeMasterKeyId ) ;
2021-10-03 17:00:49 +02:00
const previousE2EE = localInfo . e2ee ;
logger . info ( 'Sync target info differs between local and remote - merging infos: ' , newInfo . toObject ( ) ) ;
2021-08-12 17:54:10 +02:00
2021-11-03 14:26:26 +02:00
await this . lockHandler ( ) . acquireLock ( LockType . Exclusive , this . lockClientType ( ) , this . clientId_ , { clearExistingSyncLocksFromTheSameClient : true } ) ;
2021-10-03 17:00:49 +02:00
await uploadSyncInfo ( this . api ( ) , newInfo ) ;
await saveLocalSyncInfo ( newInfo ) ;
2021-11-03 14:26:26 +02:00
await this . lockHandler ( ) . releaseLock ( LockType . Exclusive , this . lockClientType ( ) , this . clientId_ ) ;
2021-08-12 17:54:10 +02:00
2021-10-03 17:00:49 +02:00
// console.info('NEW', newInfo);
if ( newInfo . e2ee !== previousE2EE ) {
if ( newInfo . e2ee ) {
const mk = getActiveMasterKey ( newInfo ) ;
await setupAndEnableEncryption ( this . encryptionService ( ) , mk ) ;
} else {
await setupAndDisableEncryption ( this . encryptionService ( ) ) ;
2021-08-12 17:54:10 +02:00
}
}
2021-10-03 17:00:49 +02:00
} else {
// Set it to remote anyway so that timestamps are the same
// Note: that's probably not needed anymore?
// await uploadSyncInfo(this.api(), remoteInfo);
2020-08-02 13:28:50 +02:00
}
} catch ( error ) {
if ( error . code === 'outdatedSyncTarget' ) {
Setting . setValue ( 'sync.upgradeState' , Setting . SYNC_UPGRADE_STATE_SHOULD_DO ) ;
}
throw error ;
}
2021-11-03 14:26:26 +02:00
syncLock = await this . lockHandler ( ) . acquireLock ( LockType . Sync , this . lockClientType ( ) , this . clientId_ ) ;
2020-08-02 13:28:50 +02:00
2020-11-12 21:13:28 +02:00
this . lockHandler ( ) . startAutoLockRefresh ( syncLock , ( error : any ) = > {
2021-08-07 13:22:37 +02:00
logger . warn ( 'Could not refresh lock - cancelling sync. Error was:' , error ) ;
2020-08-02 13:28:50 +02:00
this . syncTargetIsLocked_ = true ;
2020-11-25 16:40:25 +02:00
void this . cancel ( ) ;
2020-08-02 13:28:50 +02:00
} ) ;
2019-10-10 23:23:11 +02:00
2021-09-18 16:02:24 +02:00
// ========================================================================
// 2. DELETE_REMOTE
// ------------------------------------------------------------------------
// Delete the remote items that have been deleted locally.
// ========================================================================
if ( syncSteps . indexOf ( 'delete_remote' ) >= 0 ) {
const deletedItems = await BaseItem . deletedItems ( syncTargetId ) ;
for ( let i = 0 ; i < deletedItems . length ; i ++ ) {
if ( this . cancelling ( ) ) break ;
const item = deletedItems [ i ] ;
const path = BaseItem . systemPath ( item . item_id ) ;
this . logSyncOperation ( 'deleteRemote' , null , { id : item.item_id } , 'local has been deleted' ) ;
await this . apiCall ( 'delete' , path ) ;
if ( item . item_type === BaseModel . TYPE_RESOURCE ) {
const remoteContentPath = resourceRemotePath ( item . item_id ) ;
await this . apiCall ( 'delete' , remoteContentPath ) ;
}
await BaseItem . remoteDeletedItem ( syncTargetId , item . item_id ) ;
}
} // DELETE_REMOTE STEP
2018-03-09 21:07:38 +02:00
// ========================================================================
// 1. UPLOAD
// ------------------------------------------------------------------------
// First, find all the items that have been changed since the
// last sync and apply the changes to remote.
// ========================================================================
2017-06-29 20:03:16 +02:00
2019-07-29 15:43:53 +02:00
if ( syncSteps . indexOf ( 'update_remote' ) >= 0 ) {
2020-11-12 21:13:28 +02:00
const donePaths : string [ ] = [ ] ;
2019-05-16 19:34:16 +02:00
2020-11-12 21:13:28 +02:00
const completeItemProcessing = ( path : string ) = > {
2019-05-16 19:34:16 +02:00
donePaths . push ( path ) ;
2019-07-29 15:43:53 +02:00
} ;
2019-05-16 19:34:16 +02:00
2018-03-09 21:07:38 +02:00
while ( true ) {
2017-07-09 17:47:05 +02:00
if ( this . cancelling ( ) ) break ;
2020-03-14 01:46:14 +02:00
const result = await BaseItem . itemsThatNeedSync ( syncTargetId ) ;
const locals = result . items ;
2018-03-09 21:07:38 +02:00
2021-06-18 18:17:25 +02:00
await itemUploader . preUploadItems ( result . items . filter ( ( it : any ) = > result . neverSyncedItemIds . includes ( it . id ) ) ) ;
2018-03-09 21:07:38 +02:00
for ( let i = 0 ; i < locals . length ; i ++ ) {
if ( this . cancelling ( ) ) break ;
2017-06-14 00:39:45 +02:00
2018-03-09 21:07:38 +02:00
let local = locals [ i ] ;
2021-10-15 13:38:14 +02:00
const ItemClass : typeof BaseItem = BaseItem . itemClass ( local ) ;
2020-03-14 01:46:14 +02:00
const path = BaseItem . systemPath ( local ) ;
2018-03-09 21:07:38 +02:00
// Safety check to avoid infinite loops.
2018-12-08 01:41:39 +02:00
// - In fact this error is possible if the item is marked for sync (via sync_time or force_sync) while synchronisation is in
// progress. In that case exit anyway to be sure we aren't in a loop and the item will be re-synced next time.
// - It can also happen if the item is directly modified in the sync target, and set with an update_time in the future. In that case,
// the local sync_time will be updated to Date.now() but on the next loop it will see that the remote item still has a date ahead
// and will see a conflict. There's currently no automatic fix for this - the remote item on the sync target must be fixed manually
// (by setting an updated_time less than current time).
2019-07-29 15:43:53 +02:00
if ( donePaths . indexOf ( path ) >= 0 ) throw new JoplinError ( sprintf ( 'Processing a path that has already been done: %s. sync_time was not updated? Remote item has an updated_time in the future?' , path ) , 'processingPathTwice' ) ;
2018-03-09 21:07:38 +02:00
2021-06-17 12:24:02 +02:00
const remote : RemoteItem = result . neverSyncedItemIds . includes ( local . id ) ? null : await this . apiCall ( 'stat' , path ) ;
2018-03-09 21:07:38 +02:00
let action = null ;
2019-07-29 15:58:33 +02:00
2019-07-29 15:43:53 +02:00
let reason = '' ;
2018-03-09 21:07:38 +02:00
let remoteContent = null ;
2020-11-12 21:13:28 +02:00
const getConflictType = ( conflictedItem : any ) = > {
2020-05-31 17:57:16 +02:00
if ( conflictedItem . type_ === BaseModel . TYPE_NOTE ) return 'noteConflict' ;
if ( conflictedItem . type_ === BaseModel . TYPE_RESOURCE ) return 'resourceConflict' ;
return 'itemConflict' ;
} ;
2018-03-09 21:07:38 +02:00
if ( ! remote ) {
if ( ! local . sync_time ) {
2019-07-29 15:43:53 +02:00
action = 'createRemote' ;
reason = 'remote does not exist, and local is new and has never been synced' ;
2017-12-05 01:38:09 +02:00
} else {
2018-03-09 21:07:38 +02:00
// Note or item was modified after having been deleted remotely
2018-10-30 02:17:50 +02:00
// "itemConflict" is for all the items except the notes, which are dealt with in a special way
2020-05-31 17:57:16 +02:00
action = getConflictType ( local ) ;
2019-07-29 15:43:53 +02:00
reason = 'remote has been deleted, but local has changes' ;
2017-08-01 23:40:14 +02:00
}
2018-03-09 21:07:38 +02:00
} else {
// Note: in order to know the real updated_time value, we need to load the content. In theory we could
// rely on the file timestamp (in remote.updated_time) but in practice it's not accurate enough and
// can lead to conflicts (for example when the file timestamp is slightly ahead of it's real
// updated_time). updated_time is set and managed by clients so it's always accurate.
// Same situation below for updateLocal.
//
// This is a bit inefficient because if the resulting action is "updateRemote" we don't need the whole
// content, but for now that will do since being reliable is the priority.
//
2019-01-18 19:56:56 +02:00
// Note: assuming a particular sync target is guaranteed to have accurate timestamps, the driver maybe
2018-03-09 21:07:38 +02:00
// could expose this with a accurateTimestamps() method that returns "true". In that case, the test
2018-05-05 16:25:37 +02:00
// could be done using the file timestamp and the potentially unnecessary content loading could be skipped.
2018-03-09 21:07:38 +02:00
// OneDrive does not appear to have accurate timestamps as lastModifiedDateTime would occasionally be
// a few seconds ahead of what it was set with setTimestamp()
2018-06-18 09:47:51 +02:00
try {
2020-08-02 13:28:50 +02:00
remoteContent = await this . apiCall ( 'get' , path ) ;
2018-06-18 09:47:51 +02:00
} catch ( error ) {
if ( error . code === 'rejectedByTarget' ) {
this . progressReport_ . errors . push ( error ) ;
2021-08-07 13:22:37 +02:00
logger . warn ( ` Rejected by target: ${ path } : ${ error . message } ` ) ;
2019-05-16 19:34:16 +02:00
completeItemProcessing ( path ) ;
2018-06-18 09:47:51 +02:00
continue ;
} else {
throw error ;
}
}
2019-09-19 23:51:18 +02:00
if ( ! remoteContent ) throw new Error ( ` Got metadata for path but could not fetch content: ${ path } ` ) ;
2018-03-09 21:07:38 +02:00
remoteContent = await BaseItem . unserialize ( remoteContent ) ;
if ( remoteContent . updated_time > local . sync_time ) {
// Since, in this loop, we are only dealing with items that require sync, if the
// remote has been modified after the sync time, it means both items have been
// modified and so there's a conflict.
2020-05-31 17:57:16 +02:00
action = getConflictType ( local ) ;
2019-07-29 15:43:53 +02:00
reason = 'both remote and local have changes' ;
2017-12-05 01:38:09 +02:00
} else {
2019-07-29 15:43:53 +02:00
action = 'updateRemote' ;
reason = 'local has changes' ;
2017-12-05 01:38:09 +02:00
}
}
2021-08-12 17:54:10 +02:00
// We no longer upload Master Keys however we keep them
// in the database for extra safety. In a future
// version, once it's confirmed that the new E2EE system
// works well, we can delete them.
if ( local . type_ === ModelType . MasterKey ) action = null ;
2018-03-09 21:07:38 +02:00
this . logSyncOperation ( action , local , remote , reason ) ;
2017-12-12 20:41:02 +02:00
2021-07-16 12:48:54 +02:00
if ( local . type_ == BaseModel . TYPE_RESOURCE && ( action == 'createRemote' || action === 'updateRemote' ) ) {
2019-05-16 19:34:16 +02:00
const localState = await Resource . localState ( local . id ) ;
if ( localState . fetch_status !== Resource . FETCH_STATUS_DONE ) {
2021-06-16 14:03:10 +02:00
// This condition normally shouldn't happen
// because the normal cases are as follow:
//
// - User creates a resource locally - in that
// case the fetch status is DONE, so we cannot
// end up here.
//
// - User fetches a new resource metadata, but
// not the blob - in that case fetch status is
// IDLE. However in that case, we cannot end
// up in this place either, because the action
// cannot be createRemote (because the
// resource has not been created locally) or
// updateRemote (because a resouce cannot be
// modified locally unless the blob is present
// too).
//
// Possibly the only case we can end up here is
// if a resource metadata has been downloaded,
// but not the blob yet. Then the sync target is
// switched to a different one. In that case, we
// can have a fetch status IDLE, with an
// "updateRemote" action, if the timestamp of
// the server resource is before the timestamp
// of the local resource.
//
// In that case we can't do much so we mark the
// resource as "cannot sync". Otherwise it will
// throw the error "Processing a path that has
// already been done" on the next loop, and sync
// will never finish because we'll always end up
// here.
2021-08-07 13:22:37 +02:00
logger . info ( ` Need to upload a resource, but blob is not present: ${ path } ` ) ;
2021-06-16 14:03:10 +02:00
await handleCannotSyncItem ( ItemClass , syncTargetId , local , 'Trying to upload resource, but only metadata is present.' ) ;
2019-05-16 19:34:16 +02:00
action = null ;
} else {
try {
2019-07-13 16:57:53 +02:00
const remoteContentPath = resourceRemotePath ( local . id ) ;
2019-05-16 19:34:16 +02:00
const result = await Resource . fullPathForSyncUpload ( local ) ;
2021-06-17 13:39:06 +02:00
const resource = result . resource ;
local = resource as any ;
2019-05-16 19:34:16 +02:00
const localResourceContentPath = result . path ;
2019-11-20 20:18:58 +02:00
2021-06-17 13:39:06 +02:00
if ( resource . size >= 10 * 1000 * 1000 ) {
2021-08-07 13:22:37 +02:00
logger . warn ( ` Uploading a large resource (resourceId: ${ local . id } , size: ${ resource . size } bytes) which may tie up the sync process. ` ) ;
2019-11-20 20:18:58 +02:00
}
2021-06-17 13:39:06 +02:00
await this . apiCall ( 'put' , remoteContentPath , null , { path : localResourceContentPath , source : 'file' , shareId : resource.share_id } ) ;
2019-05-16 19:34:16 +02:00
} catch ( error ) {
2021-05-15 20:56:49 +02:00
if ( isCannotSyncError ( error ) ) {
2019-05-16 19:34:16 +02:00
await handleCannotSyncItem ( ItemClass , syncTargetId , local , error . message ) ;
action = null ;
} else {
throw error ;
}
2018-03-09 21:07:38 +02:00
}
}
2017-11-03 00:48:17 +02:00
}
2019-07-29 15:43:53 +02:00
if ( action == 'createRemote' || action == 'updateRemote' ) {
2018-03-09 21:07:38 +02:00
let canSync = true ;
try {
2019-07-29 15:43:53 +02:00
if ( this . testingHooks_ . indexOf ( 'notesRejectedByTarget' ) >= 0 && local . type_ === BaseModel . TYPE_NOTE ) throw new JoplinError ( 'Testing rejectedByTarget' , 'rejectedByTarget' ) ;
2021-06-18 18:17:25 +02:00
await itemUploader . serializeAndUploadItem ( ItemClass , path , local ) ;
2018-03-09 21:07:38 +02:00
} catch ( error ) {
2019-07-29 15:43:53 +02:00
if ( error && error . code === 'rejectedByTarget' ) {
2019-05-12 02:15:52 +02:00
await handleCannotSyncItem ( ItemClass , syncTargetId , local , error . message ) ;
2018-03-09 21:07:38 +02:00
canSync = false ;
} else {
throw error ;
}
}
2017-06-19 20:58:49 +02:00
2018-03-09 21:07:38 +02:00
// Note: Currently, we set sync_time to update_time, which should work fine given that the resolution is the millisecond.
// In theory though, this could happen:
//
// 1. t0: Editor: Note is modified
// 2. t0: Sync: Found that note was modified so start uploading it
// 3. t0: Editor: Note is modified again
// 4. t1: Sync: Note has finished uploading, set sync_time to t0
//
// Later any attempt to sync will not detect that note was modified in (3) (within the same millisecond as it was being uploaded)
// because sync_time will be t0 too.
//
// The solution would be to use something like an etag (a simple counter incremented on every change) to make sure each
// change is uniquely identified. Leaving it like this for now.
if ( canSync ) {
// 2018-01-21: Setting timestamp is not needed because the delta() logic doesn't rely
// on it (instead it uses a more reliable `context` object) and the itemsThatNeedSync loop
// above also doesn't use it because it fetches the whole remote object and read the
// more reliable 'updated_time' property. Basically remote.updated_time is deprecated.
await ItemClass . saveSyncTime ( syncTargetId , local , local . updated_time ) ;
}
2019-07-29 15:43:53 +02:00
} else if ( action == 'itemConflict' ) {
2018-03-09 21:07:38 +02:00
// ------------------------------------------------------------------------------
// For non-note conflicts, we take the remote version (i.e. the version that was
// synced first) and overwrite the local content.
// ------------------------------------------------------------------------------
if ( remote ) {
local = remoteContent ;
const syncTimeQueries = BaseItem . updateSyncTimeQueries ( syncTargetId , local , time . unixMs ( ) ) ;
2019-05-06 22:35:29 +02:00
await ItemClass . save ( local , { autoTimestamp : false , changeSource : ItemChange.SOURCE_SYNC , nextQueries : syncTimeQueries } ) ;
2018-03-09 21:07:38 +02:00
} else {
2021-10-15 13:38:14 +02:00
await ItemClass . delete ( local . id , {
changeSource : ItemChange.SOURCE_SYNC ,
trackDeleted : false ,
} ) ;
2018-03-09 21:07:38 +02:00
}
2019-07-29 15:43:53 +02:00
} else if ( action == 'noteConflict' ) {
2018-03-09 21:07:38 +02:00
// ------------------------------------------------------------------------------
// First find out if the conflict matters. For example, if the conflict is on the title or body
// we want to preserve all the changes. If it's on todo_completed it doesn't really matter
// so in this case we just take the remote content.
// ------------------------------------------------------------------------------
let mustHandleConflict = true ;
if ( remoteContent ) {
mustHandleConflict = Note . mustHandleConflict ( local , remoteContent ) ;
}
2017-11-03 00:48:17 +02:00
2018-03-09 21:07:38 +02:00
// ------------------------------------------------------------------------------
// Create a duplicate of local note into Conflicts folder
// (to preserve the user's changes)
// ------------------------------------------------------------------------------
2017-11-03 00:48:17 +02:00
2018-03-09 21:07:38 +02:00
if ( mustHandleConflict ) {
2021-06-12 09:46:49 +02:00
await Note . createConflictNote ( local , ItemChange . SOURCE_SYNC ) ;
2018-03-09 21:07:38 +02:00
}
2020-05-31 17:57:16 +02:00
} else if ( action == 'resourceConflict' ) {
// ------------------------------------------------------------------------------
// Unlike notes we always handle the conflict for resources
// ------------------------------------------------------------------------------
2020-05-31 18:43:51 +02:00
await Resource . createConflictResourceNote ( local ) ;
if ( remote ) {
// The local content we have is no longer valid and should be re-downloaded
await Resource . setLocalState ( local . id , {
fetch_status : Resource.FETCH_STATUS_IDLE ,
} ) ;
}
2020-05-31 17:57:16 +02:00
}
2018-02-16 19:55:50 +02:00
2020-05-31 17:57:16 +02:00
if ( [ 'noteConflict' , 'resourceConflict' ] . includes ( action ) ) {
2018-03-09 21:07:38 +02:00
// ------------------------------------------------------------------------------
2020-05-31 17:57:16 +02:00
// For note and resource conflicts, the creation of the conflict item is done
// differently. However the way the local content is handled is the same.
2018-03-09 21:07:38 +02:00
// Either copy the remote content to local or, if the remote content has
// been deleted, delete the local content.
// ------------------------------------------------------------------------------
if ( remote ) {
local = remoteContent ;
const syncTimeQueries = BaseItem . updateSyncTimeQueries ( syncTargetId , local , time . unixMs ( ) ) ;
2019-05-06 22:35:29 +02:00
await ItemClass . save ( local , { autoTimestamp : false , changeSource : ItemChange.SOURCE_SYNC , nextQueries : syncTimeQueries } ) ;
2018-03-09 21:07:38 +02:00
2019-07-29 15:43:53 +02:00
if ( local . encryption_applied ) this . dispatch ( { type : 'SYNC_GOT_ENCRYPTED_ITEM' } ) ;
2018-03-09 21:07:38 +02:00
} else {
// Remote no longer exists (note deleted) so delete local one too
2021-10-15 13:38:14 +02:00
await ItemClass . delete ( local . id , { changeSource : ItemChange.SOURCE_SYNC , trackDeleted : false } ) ;
2018-03-09 21:07:38 +02:00
}
2017-06-29 20:03:16 +02:00
}
2018-03-09 21:07:38 +02:00
2019-05-16 19:34:16 +02:00
completeItemProcessing ( path ) ;
2017-06-20 21:25:01 +02:00
}
2017-06-18 01:49:52 +02:00
2018-03-09 21:07:38 +02:00
if ( ! result . hasMore ) break ;
2017-06-29 20:03:16 +02:00
}
2018-03-09 21:07:38 +02:00
} // UPLOAD STEP
2017-06-24 19:40:03 +02:00
2018-03-09 21:07:38 +02:00
// ------------------------------------------------------------------------
// 3. DELTA
2017-06-29 20:03:16 +02:00
// ------------------------------------------------------------------------
// Loop through all the remote items, find those that
2018-10-30 02:17:50 +02:00
// have been created or updated, and apply the changes to local.
2017-06-29 20:03:16 +02:00
// ------------------------------------------------------------------------
2019-06-08 00:20:08 +02:00
if ( this . downloadQueue_ ) await this . downloadQueue_ . stop ( ) ;
this . downloadQueue_ = new TaskQueue ( 'syncDownload' ) ;
2021-08-07 13:22:37 +02:00
this . downloadQueue_ . logger_ = logger ;
2019-06-08 00:20:08 +02:00
2019-07-29 15:43:53 +02:00
if ( syncSteps . indexOf ( 'delta' ) >= 0 ) {
2018-03-09 21:07:38 +02:00
// At this point all the local items that have changed have been pushed to remote
// or handled as conflicts, so no conflict is possible after this.
2017-06-29 20:03:16 +02:00
2018-03-09 21:07:38 +02:00
let context = null ;
let newDeltaContext = null ;
2020-03-14 01:46:14 +02:00
const localFoldersToDelete = [ ] ;
2018-03-09 21:07:38 +02:00
let hasCancelled = false ;
if ( lastContext . delta ) context = lastContext . delta ;
2017-07-18 21:57:49 +02:00
2018-03-09 21:07:38 +02:00
while ( true ) {
if ( this . cancelling ( ) || hasCancelled ) break ;
2017-07-18 21:57:49 +02:00
2020-11-12 21:13:28 +02:00
const listResult : any = await this . apiCall ( 'delta' , '' , {
2018-03-09 21:07:38 +02:00
context : context ,
2017-10-27 00:03:21 +02:00
2018-03-09 21:07:38 +02:00
// allItemIdsHandler() provides a way for drivers that don't have a delta API to
// still provide delta functionality by comparing the items they have to the items
// the client has. Very inefficient but that's the only possible workaround.
// It's a function so that it is only called if the driver needs these IDs. For
// drivers with a delta functionality it's a noop.
allItemIdsHandler : async ( ) = > {
return BaseItem . syncedItemIds ( syncTargetId ) ;
} ,
2019-09-25 20:40:04 +02:00
wipeOutFailSafe : Setting.value ( 'sync.wipeOutFailSafe' ) ,
2019-11-13 20:54:54 +02:00
2021-08-07 13:22:37 +02:00
logger : logger ,
2018-03-09 21:07:38 +02:00
} ) ;
2017-07-23 16:11:44 +02:00
2021-06-19 11:34:44 +02:00
const remotes : RemoteItem [ ] = listResult . items ;
2018-01-08 22:36:00 +02:00
2019-07-29 15:43:53 +02:00
this . logSyncOperation ( 'fetchingTotal' , null , null , 'Fetching delta items from sync target' , remotes . length ) ;
2017-07-18 21:57:49 +02:00
2021-06-19 11:34:44 +02:00
const remoteIds = remotes . map ( r = > BaseItem . pathToId ( r . path ) ) ;
const locals = await BaseItem . loadItemsByIds ( remoteIds ) ;
2019-06-08 00:20:08 +02:00
for ( const remote of remotes ) {
if ( this . cancelling ( ) ) break ;
2021-06-19 11:34:44 +02:00
let needsToDownload = true ;
if ( this . api ( ) . supportsAccurateTimestamp ) {
const local = locals . find ( l = > l . id === BaseItem . pathToId ( remote . path ) ) ;
if ( local && local . updated_time === remote . jop_updated_time ) needsToDownload = false ;
}
if ( needsToDownload ) {
this . downloadQueue_ . push ( remote . path , async ( ) = > {
return this . apiCall ( 'get' , remote . path ) ;
} ) ;
}
2019-06-08 00:20:08 +02:00
}
2018-03-09 21:07:38 +02:00
for ( let i = 0 ; i < remotes . length ; i ++ ) {
2019-07-29 15:43:53 +02:00
if ( this . cancelling ( ) || this . testingHooks_ . indexOf ( 'cancelDeltaLoop2' ) >= 0 ) {
2018-03-09 21:07:38 +02:00
hasCancelled = true ;
break ;
2017-07-18 22:03:07 +02:00
}
2018-03-09 21:07:38 +02:00
2019-07-29 15:43:53 +02:00
this . logSyncOperation ( 'fetchingProcessed' , null , null , 'Processing fetched item' ) ;
2018-03-09 21:07:38 +02:00
2020-03-14 01:46:14 +02:00
const remote = remotes [ i ] ;
2018-03-09 21:07:38 +02:00
if ( ! BaseItem . isSystemPath ( remote . path ) ) continue ; // The delta API might return things like the .sync, .resource or the root folder
const loadContent = async ( ) = > {
2021-06-17 13:39:06 +02:00
const task = await this . downloadQueue_ . waitForResult ( path ) ;
2019-06-08 00:20:08 +02:00
if ( task . error ) throw task . error ;
if ( ! task . result ) return null ;
return await BaseItem . unserialize ( task . result ) ;
2018-03-09 21:07:38 +02:00
} ;
2020-03-14 01:46:14 +02:00
const path = remote . path ;
2021-06-19 11:34:44 +02:00
const remoteId = BaseItem . pathToId ( path ) ;
2018-03-09 21:07:38 +02:00
let action = null ;
2019-07-29 15:43:53 +02:00
let reason = '' ;
2021-06-19 11:34:44 +02:00
let local = locals . find ( l = > l . id === remoteId ) ;
2018-03-09 21:07:38 +02:00
let ItemClass = null ;
let content = null ;
2018-06-18 09:47:51 +02:00
try {
if ( ! local ) {
if ( remote . isDeleted !== true ) {
2019-07-29 15:43:53 +02:00
action = 'createLocal' ;
reason = 'remote exists but local does not' ;
2018-06-18 09:47:51 +02:00
content = await loadContent ( ) ;
ItemClass = content ? BaseItem . itemClass ( content ) : null ;
}
2018-03-09 21:07:38 +02:00
} else {
2018-06-18 09:47:51 +02:00
ItemClass = BaseItem . itemClass ( local ) ;
local = ItemClass . filter ( local ) ;
if ( remote . isDeleted ) {
2019-07-29 15:43:53 +02:00
action = 'deleteLocal' ;
reason = 'remote has been deleted' ;
2018-06-18 09:47:51 +02:00
} else {
2021-06-19 11:34:44 +02:00
if ( this . api ( ) . supportsAccurateTimestamp && remote . jop_updated_time === local . updated_time ) {
// Nothing to do, and no need to fetch the content
} else {
content = await loadContent ( ) ;
if ( content && content . updated_time > local . updated_time ) {
action = 'updateLocal' ;
reason = 'remote is more recent than local' ;
}
2018-06-18 09:47:51 +02:00
}
2018-03-09 21:07:38 +02:00
}
2017-07-18 22:03:07 +02:00
}
2018-06-18 09:47:51 +02:00
} catch ( error ) {
if ( error . code === 'rejectedByTarget' ) {
this . progressReport_ . errors . push ( error ) ;
2021-08-07 13:22:37 +02:00
logger . warn ( ` Rejected by target: ${ path } : ${ error . message } ` ) ;
2018-06-18 09:47:51 +02:00
action = null ;
} else {
2019-09-19 23:51:18 +02:00
error . message = ` On file ${ path } : ${ error . message } ` ;
2018-06-18 09:47:51 +02:00
throw error ;
}
2017-07-18 22:03:07 +02:00
}
2017-07-18 21:57:49 +02:00
2019-05-06 22:35:29 +02:00
if ( this . testingHooks_ . indexOf ( 'skipRevisions' ) >= 0 && content && content . type_ === BaseModel . TYPE_REVISION ) action = null ;
2018-03-09 21:07:38 +02:00
if ( ! action ) continue ;
2017-07-18 21:57:49 +02:00
2018-03-09 21:07:38 +02:00
this . logSyncOperation ( action , local , remote , reason ) ;
2017-07-18 21:57:49 +02:00
2019-07-29 15:43:53 +02:00
if ( action == 'createLocal' || action == 'updateLocal' ) {
2018-03-09 21:07:38 +02:00
if ( content === null ) {
2021-08-07 13:22:37 +02:00
logger . warn ( ` Remote has been deleted between now and the delta() call? In that case it will be handled during the next sync: ${ path } ` ) ;
2018-03-09 21:07:38 +02:00
continue ;
}
content = ItemClass . filter ( content ) ;
// 2017-12-03: This was added because the new user_updated_time and user_created_time properties were added
// to the items. However changing the database is not enough since remote items that haven't been synced yet
// will not have these properties and, since they are required, it would cause a problem. So this check
// if they are present and, if not, set them to a reasonable default.
// Let's leave these two lines for 6 months, by which time all the clients should have been synced.
if ( ! content . user_updated_time ) content . user_updated_time = content . updated_time ;
if ( ! content . user_created_time ) content . user_created_time = content . created_time ;
2020-11-12 21:13:28 +02:00
const options : any = {
2018-03-09 21:07:38 +02:00
autoTimestamp : false ,
nextQueries : BaseItem.updateSyncTimeQueries ( syncTargetId , content , time . unixMs ( ) ) ,
2019-05-06 22:35:29 +02:00
changeSource : ItemChange.SOURCE_SYNC ,
2018-03-09 21:07:38 +02:00
} ;
2019-07-29 15:43:53 +02:00
if ( action == 'createLocal' ) options . isNew = true ;
if ( action == 'updateLocal' ) options . oldItem = local ;
2018-03-09 21:07:38 +02:00
2020-05-31 01:31:29 +02:00
const creatingOrUpdatingResource = content . type_ == BaseModel . TYPE_RESOURCE && ( action == 'createLocal' || action == 'updateLocal' ) ;
2018-10-10 19:53:09 +02:00
2020-05-31 01:31:29 +02:00
if ( creatingOrUpdatingResource ) {
2019-05-12 02:15:52 +02:00
if ( content . size >= this . maxResourceSize ( ) ) {
2019-09-19 23:51:18 +02:00
await handleCannotSyncItem ( ItemClass , syncTargetId , content , ` File " ${ content . title } " is larger than allowed ${ this . maxResourceSize ( ) } bytes. Beyond this limit, the mobile app would crash. ` , BaseItem . SYNC_ITEM_LOCATION_REMOTE ) ;
2019-05-12 02:15:52 +02:00
continue ;
}
2018-11-13 02:45:08 +02:00
await ResourceLocalState . save ( { resource_id : content.id , fetch_status : Resource.FETCH_STATUS_IDLE } ) ;
}
2018-10-10 19:53:09 +02:00
2021-08-12 17:54:10 +02:00
if ( content . type_ === ModelType . MasterKey ) {
// Special case for master keys - if we download
// one, we only add it to the store if it's not
// already there. That can happen for example if
// the new E2EE migration was processed at a
// time a master key was still on the sync
// target. In that case, info.json would not
// have it.
//
// If info.json already has the key we shouldn't
// update because the most up to date keys
// should always be in info.json now.
const existingMasterKey = await MasterKey . load ( content . id ) ;
if ( ! existingMasterKey ) {
logger . info ( ` Downloaded a master key that was not in info.json - adding it to the store. ID: ${ content . id } ` ) ;
await MasterKey . save ( content ) ;
}
} else {
await ItemClass . save ( content , options ) ;
}
2018-03-09 21:07:38 +02:00
2020-05-31 01:31:29 +02:00
if ( creatingOrUpdatingResource ) this . dispatch ( { type : 'SYNC_CREATED_OR_UPDATED_RESOURCE' , id : content.id } ) ;
2018-10-08 20:11:53 +02:00
2021-08-12 17:54:10 +02:00
// if (!hasAutoEnabledEncryption && content.type_ === BaseModel.TYPE_MASTER_KEY && !masterKeysBefore) {
// hasAutoEnabledEncryption = true;
// logger.info('One master key was downloaded and none was previously available: automatically enabling encryption');
// logger.info('Using master key: ', content.id);
// await this.encryptionService().enableEncryption(content);
// await this.encryptionService().loadMasterKeysFromSettings();
// logger.info('Encryption has been enabled with downloaded master key as active key. However, note that no password was initially supplied. It will need to be provided by user.');
// }
2017-07-18 22:03:07 +02:00
2019-07-29 15:43:53 +02:00
if ( content . encryption_applied ) this . dispatch ( { type : 'SYNC_GOT_ENCRYPTED_ITEM' } ) ;
} else if ( action == 'deleteLocal' ) {
2018-03-09 21:07:38 +02:00
if ( local . type_ == BaseModel . TYPE_FOLDER ) {
localFoldersToDelete . push ( local ) ;
continue ;
}
2017-07-18 22:03:07 +02:00
2020-03-14 01:46:14 +02:00
const ItemClass = BaseItem . itemClass ( local . type_ ) ;
2020-07-28 19:50:34 +02:00
await ItemClass . delete ( local . id , { trackDeleted : false , changeSource : ItemChange.SOURCE_SYNC } ) ;
2017-12-21 21:06:08 +02:00
}
2018-03-09 21:07:38 +02:00
}
2017-12-21 21:06:08 +02:00
2018-03-09 21:07:38 +02:00
// If user has cancelled, don't record the new context (2) so that synchronisation
// can start again from the previous context (1) next time. It is ok if some items
// have been synced between (1) and (2) because the loop above will handle the same
2018-05-05 16:25:37 +02:00
// items being synced twice as an update. If the local and remote items are identical
2018-03-09 21:07:38 +02:00
// the update will simply be skipped.
if ( ! hasCancelled ) {
2018-06-11 00:16:27 +02:00
if ( options . saveContextHandler ) {
const deltaToSave = Object . assign ( { } , listResult . context ) ;
// Remove these two variables because they can be large and can be rebuilt
// the next time the sync is started.
delete deltaToSave . statsCache ;
delete deltaToSave . statIdsCache ;
options . saveContextHandler ( { delta : deltaToSave } ) ;
}
2018-03-09 21:07:38 +02:00
if ( ! listResult . hasMore ) {
newDeltaContext = listResult . context ;
break ;
2017-07-18 22:03:07 +02:00
}
2018-03-09 21:07:38 +02:00
context = listResult . context ;
2017-07-18 22:03:07 +02:00
}
}
2018-03-09 21:07:38 +02:00
outputContext . delta = newDeltaContext ? newDeltaContext : lastContext.delta ;
// ------------------------------------------------------------------------
// Delete the folders that have been collected in the loop above.
// Folders are always deleted last, and only if they are empty.
// If they are not empty it's considered a conflict since whatever deleted
// them should have deleted their content too. In that case, all its notes
// are marked as "is_conflict".
// ------------------------------------------------------------------------
if ( ! this . cancelling ( ) ) {
for ( let i = 0 ; i < localFoldersToDelete . length ; i ++ ) {
const item = localFoldersToDelete [ i ] ;
const noteIds = await Folder . noteIds ( item . id ) ;
if ( noteIds . length ) {
// CONFLICT
await Folder . markNotesAsConflict ( item . id ) ;
}
2019-05-06 22:35:29 +02:00
await Folder . delete ( item . id , { deleteChildren : false , changeSource : ItemChange.SOURCE_SYNC , trackDeleted : false } ) ;
2017-11-21 20:17:50 +02:00
}
2017-07-18 22:03:07 +02:00
}
2017-07-18 21:57:49 +02:00
2018-03-09 21:07:38 +02:00
if ( ! this . cancelling ( ) ) {
await BaseItem . deleteOrphanSyncItems ( ) ;
2017-07-18 22:03:07 +02:00
}
2018-03-09 21:07:38 +02:00
} // DELTA STEP
2017-06-29 20:03:16 +02:00
} catch ( error ) {
2019-10-10 23:23:11 +02:00
if ( throwOnError ) {
errorToThrow = error ;
2020-08-02 13:28:50 +02:00
} else if ( error && [ 'cannotEncryptEncrypted' , 'noActiveMasterKey' , 'processingPathTwice' , 'failSafe' , 'lockError' , 'outdatedSyncTarget' ] . indexOf ( error . code ) >= 0 ) {
2017-12-20 21:45:25 +02:00
// Only log an info statement for this since this is a common condition that is reported
2019-04-29 19:27:32 +02:00
// in the application, and needs to be resolved by the user.
// Or it's a temporary issue that will be resolved on next sync.
2021-08-07 13:22:37 +02:00
logger . info ( error . message ) ;
2019-09-25 20:58:15 +02:00
2020-08-02 13:28:50 +02:00
if ( error . code === 'failSafe' || error . code === 'lockError' ) {
2019-09-27 20:12:28 +02:00
// Get the message to display on UI, but not in testing to avoid poluting stdout
if ( ! shim . isTestingEnv ( ) ) this . progressReport_ . errors . push ( error . message ) ;
this . logLastRequests ( ) ;
}
2019-05-01 00:42:06 +02:00
} else if ( error . code === 'unknownItemType' ) {
this . progressReport_ . errors . push ( _ ( 'Unknown item type downloaded - please upgrade Joplin to the latest version' ) ) ;
2021-08-07 13:22:37 +02:00
logger . error ( error ) ;
2017-12-17 21:51:45 +02:00
} else {
2021-08-07 13:22:37 +02:00
logger . error ( error ) ;
if ( error . details ) logger . error ( 'Details:' , error . details ) ;
2018-03-09 21:51:01 +02:00
// Don't save to the report errors that are due to things like temporary network errors or timeout.
2019-09-25 20:58:15 +02:00
if ( ! shim . fetchRequestCanBeRetried ( error ) ) {
this . progressReport_ . errors . push ( error ) ;
this . logLastRequests ( ) ;
}
2017-12-17 21:51:45 +02:00
}
2017-06-20 21:18:19 +02:00
}
2017-05-18 21:58:01 +02:00
2020-08-02 13:28:50 +02:00
if ( syncLock ) {
this . lockHandler ( ) . stopAutoLockRefresh ( syncLock ) ;
2021-11-03 14:26:26 +02:00
await this . lockHandler ( ) . releaseLock ( LockType . Sync , this . lockClientType ( ) , this . clientId_ ) ;
2020-08-02 13:28:50 +02:00
}
this . syncTargetIsLocked_ = false ;
2017-07-09 17:47:05 +02:00
if ( this . cancelling ( ) ) {
2021-08-07 13:22:37 +02:00
logger . info ( 'Synchronisation was cancelled.' ) ;
2017-07-09 17:47:05 +02:00
this . cancelling_ = false ;
}
2021-05-13 18:57:37 +02:00
// After syncing, we run the share service maintenance, which is going
// to fetch share invitations, if any.
if ( this . shareService_ ) {
try {
await this . shareService_ . maintenance ( ) ;
} catch ( error ) {
2021-08-07 13:22:37 +02:00
logger . error ( 'Could not run share service maintenance:' , error ) ;
2021-05-13 18:57:37 +02:00
}
}
2017-07-16 23:17:22 +02:00
this . progressReport_ . completedTime = time . unixMs ( ) ;
2019-09-19 23:51:18 +02:00
this . logSyncOperation ( 'finished' , null , null , ` Synchronisation finished [ ${ synchronizationId } ] ` ) ;
2017-07-18 00:43:29 +02:00
2017-07-14 21:06:01 +02:00
await this . logSyncSummary ( this . progressReport_ ) ;
2020-12-08 21:03:22 +02:00
eventManager . emit ( 'syncComplete' , {
withErrors : Synchronizer.reportHasErrors ( this . progressReport_ ) ,
} ) ;
2019-07-30 09:35:42 +02:00
this . onProgress_ = function ( ) { } ;
2017-07-14 21:06:01 +02:00
this . progressReport_ = { } ;
2017-07-16 23:17:22 +02:00
2020-04-08 02:00:01 +02:00
this . dispatch ( { type : 'SYNC_COMPLETED' , isFullSync : this.isFullSync ( syncSteps ) } ) ;
2017-07-30 22:22:57 +02:00
2018-03-09 22:59:12 +02:00
this . state_ = 'idle' ;
2017-07-18 21:57:49 +02:00
2019-10-10 23:23:11 +02:00
if ( errorToThrow ) throw errorToThrow ;
2017-07-18 21:57:49 +02:00
return outputContext ;
2017-05-18 21:58:01 +02:00
}
}