diff --git a/Sources/Backup/LocalBackup/OASettingsHelper.mm b/Sources/Backup/LocalBackup/OASettingsHelper.mm index 3f6acbdace..60ae6609d7 100644 --- a/Sources/Backup/LocalBackup/OASettingsHelper.mm +++ b/Sources/Backup/LocalBackup/OASettingsHelper.mm @@ -70,6 +70,8 @@ #import "OASearchHistorySettingsItem.h" #import "OATileSource.h" #import "OAPluginsHelper.h" +#import "OABackupHelper.h" +#import "OAOperationLog.h" #include #include @@ -90,6 +92,9 @@ @implementation OASettingsHelper { __weak OAImportSettingsViewController *_importDataVC; NSInteger _currentBackupVersion; + + // COLLECT_LOCAL_DIAG: remove after cloud sync performance investigation. + OAOperationLog *_cloudSyncOperationLog; } + (OASettingsHelper *) sharedInstance @@ -108,6 +113,7 @@ - (instancetype)init if (self) { _currentBackupVersion = kVersion; + _cloudSyncOperationLog = [[OAOperationLog alloc] initWithOperationName:@"cloudSyncSettings" debug:BACKUP_DEBUG_LOGS]; } return self; } @@ -224,12 +230,30 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin - (NSArray *) getFilteredSettingsItems:(NSArray *)settingsTypes addProfiles:(BOOL)addProfiles doExport:(BOOL)doExport { + [_cloudSyncOperationLog startOperation:@"COLLECT_LOCAL_DIAG getFilteredSettingsItems"]; + CFAbsoluteTime phaseStartTime = CFAbsoluteTimeGetCurrent(); NSMutableDictionary *typesMap = [NSMutableDictionary new]; [typesMap addEntriesFromDictionary:[self getSettingsItems:addProfiles]]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG getSettingsItems END duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; + + phaseStartTime = CFAbsoluteTimeGetCurrent(); [typesMap addEntriesFromDictionary:[self getMyPlacesItems:NO]]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG getMyPlacesItems END duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; + + phaseStartTime = CFAbsoluteTimeGetCurrent(); [typesMap addEntriesFromDictionary:[self getResourcesItems]]; - - return [self getFilteredSettingsItems:typesMap settingsTypes:settingsTypes settingsItems:@[] doExport:doExport]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG getResourcesItems END duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; + + phaseStartTime = CFAbsoluteTimeGetCurrent(); + NSArray *result = [self getFilteredSettingsItems:typesMap settingsTypes:settingsTypes settingsItems:@[] doExport:doExport]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG prepareFilteredItems END duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + result.count]]; + [_cloudSyncOperationLog finishOperation:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG items=%ld", result.count]]; + return result; } - (NSArray *) getFilteredSettingsItems:(NSDictionary *)allSettingsMap @@ -243,7 +267,14 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin NSArray *settingsDataObjects = allSettingsMap[settingsType]; if (settingsDataObjects != nil) { - [filteredSettingsItems addObjectsFromArray:[self prepareSettingsItems:settingsDataObjects settingsItems:settingsItems doExport:doExport]]; + CFAbsoluteTime typeStartTime = CFAbsoluteTimeGetCurrent(); + NSArray *preparedItems = [self prepareSettingsItems:settingsDataObjects settingsItems:settingsItems doExport:doExport]; + [filteredSettingsItems addObjectsFromArray:preparedItems]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG prepareSettingsItems type=%@ duration=%.3f ms input=%ld output=%ld", + settingsType.name, + (CFAbsoluteTimeGetCurrent() - typeStartTime) * 1000, + settingsDataObjects.count, + preparedItems.count]]; } } return filteredSettingsItems; @@ -269,6 +300,8 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin - (NSDictionary *) getSettingsItems:(BOOL)addProfiles { + CFAbsoluteTime methodStartTime = CFAbsoluteTimeGetCurrent(); + CFAbsoluteTime phaseStartTime = methodStartTime; MutableOrderedDictionary *settingsItems = [MutableOrderedDictionary new]; if (addProfiles) @@ -281,7 +314,10 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin settingsItems[OAExportSettingsType.PROFILE] = appModeBeans; } settingsItems[OAExportSettingsType.GLOBAL] = @[[[OAGlobalSettingsItem alloc] init]]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG settings profiles/global duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); OAMapButtonsHelper *buttonsHelper = [OAMapButtonsHelper sharedInstance]; NSArray *buttonStates = [buttonsHelper getButtonsStates]; if (buttonStates.count == 1) @@ -297,7 +333,11 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin NSArray *actionsList = [registry getButtonsStates]; if (actionsList.count > 0) settingsItems[OAExportSettingsType.QUICK_ACTIONS] = actionsList; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG settings quickActions duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + actionsList.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); NSArray *poiList = [OAPOIFiltersHelper.sharedInstance getUserDefinedPoiFilters:NO]; if (poiList.count > 0) settingsItems[OAExportSettingsType.POI_TYPES] = poiList; @@ -305,7 +345,12 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin NSArray *impassableRoads = OAAvoidSpecificRoads.instance.getImpassableRoads; if (impassableRoads.count > 0) settingsItems[OAExportSettingsType.AVOID_ROADS] = impassableRoads; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG settings poi/avoidRoads duration=%.3f ms poi=%ld roads=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + poiList.count, + impassableRoads.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); NSFileManager *fileManager = NSFileManager.defaultManager; BOOL isDir = NO; NSString *colorPaletteFolder = [OsmAndApp instance].colorsPalettePath; @@ -345,17 +390,27 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin } } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG settings colorPalette duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG settings TOTAL duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - methodStartTime) * 1000]]; return settingsItems; } - (NSDictionary *)getMyPlacesItems:(BOOL)sorted { + CFAbsoluteTime methodStartTime = CFAbsoluteTimeGetCurrent(); + CFAbsoluteTime phaseStartTime = methodStartTime; MutableOrderedDictionary *myPlacesItems = [MutableOrderedDictionary new]; NSArray *favoriteGroups = [OAFavoritesHelper getFavoriteGroups]; if (favoriteGroups.count > 0) myPlacesItems[OAExportSettingsType.FAVORITES] = favoriteGroups; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG myPlaces favorites duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + favoriteGroups.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); NSFileManager *fileManager = NSFileManager.defaultManager; NSArray *gpsDataItems; if (sorted) @@ -384,7 +439,11 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin if (files.count > 0) myPlacesItems[OAExportSettingsType.TRACKS] = files; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG myPlaces tracks duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + gpsDataItems.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); OAOsmEditingPlugin *osmEditingPlugin = (OAOsmEditingPlugin *) [OAPluginsHelper getPlugin:OAOsmEditingPlugin.class]; if (osmEditingPlugin) { @@ -395,6 +454,9 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin if (editsPointList.count > 0) myPlacesItems[OAExportSettingsType.OSM_EDITS] = editsPointList; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG myPlaces osm duration=%.3f ms enabled=%d", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + osmEditingPlugin != nil]]; // TODO: implement after adding Audio/video notes // AudioVideoNotesPlugin plugin = OsmandPlugin.getPlugin(AudioVideoNotesPlugin.class); // if (plugin != null) { @@ -409,6 +471,7 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin // myPlacesItems.put(ExportSettingsType.MULTIMEDIA_NOTES, files); // } // } + phaseStartTime = CFAbsoluteTimeGetCurrent(); NSArray *mapMarkers = [OADestinationsHelper.instance sortedDestinationsWithoutParking]; if (mapMarkers.count > 0) { @@ -437,12 +500,22 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin NSArray *navigationHistoryEntries = [historyHelper getPointsFromNavigation:0]; if (navigationHistoryEntries.count > 0) myPlacesItems[OAExportSettingsType.NAVIGATION_HISTORY] = navigationHistoryEntries; - + + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG myPlaces markers/history duration=%.3f ms markers=%ld history=%ld/%ld/%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + mapMarkers.count, + markersHistory.count, + searchHistoryEntries.count, + navigationHistoryEntries.count]]; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG myPlaces TOTAL duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - methodStartTime) * 1000]]; return myPlacesItems; } - (NSDictionary *)getResourcesItems { + CFAbsoluteTime methodStartTime = CFAbsoluteTimeGetCurrent(); + CFAbsoluteTime phaseStartTime = methodStartTime; MutableOrderedDictionary *resourcesItems = [MutableOrderedDictionary new]; NSArray *mapStyleFiles = [OARendererRegistry getPathExternalRenderers]; @@ -465,11 +538,14 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin if (items.count > 0) resourcesItems[OAExportSettingsType.CUSTOM_ROUTING] = items; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG resources renderers/routing duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; // List onlineRoutingEngines = app.getOnlineRoutingHelper().getEngines(); // if (!Algorithms.isEmpty(onlineRoutingEngines)) { // resourcesItems.put(ExportSettingsType.ONLINE_ROUTING_ENGINES, onlineRoutingEngines); // } // TODO: implement export! + phaseStartTime = CFAbsoluteTimeGetCurrent(); NSMutableArray *tileSources = [NSMutableArray new]; NSArray *tileResources = [OAResourcesUIHelper getSortedRasterMapSources:YES]; for (OAResourceItem *res in tileResources) @@ -492,7 +568,12 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin } if (tileSources.count > 0) resourcesItems[OAExportSettingsType.MAP_SOURCES] = tileSources; + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG resources rasterSources duration=%.3f ms resources=%ld sources=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + tileResources.count, + tileSources.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); QSet types; types << OsmAnd::ResourcesManager::ResourceType::MapRegion; NSArray *localIndexFiles = [OAResourcesUIHelper getInstalledResourcePathsByTypes:types includeHidden:NO]; @@ -503,7 +584,11 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin }]; resourcesItems[OAExportSettingsType.STANDARD_MAPS] = sortedFiles; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG resources standardMaps duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + localIndexFiles.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); QSet wikiTypes; wikiTypes << OsmAnd::ResourcesManager::ResourceType::WikiMapRegion; wikiTypes << OsmAnd::ResourcesManager::ResourceType::Travel; @@ -515,7 +600,11 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin }]; resourcesItems[OAExportSettingsType.WIKI_AND_TRAVEL] = sortedFiles; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG resources wikiTravel duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + wikiFiles.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); QSet nauticalTypes; nauticalTypes << OsmAnd::ResourcesManager::ResourceType::DepthMapRegion; NSArray *nauticalFiles = [OAResourcesUIHelper getInstalledResourcePathsByTypes:nauticalTypes includeHidden:NO]; @@ -526,7 +615,11 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin }]; resourcesItems[OAExportSettingsType.DEPTH_DATA] = sortedFiles; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG resources nautical duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + nauticalFiles.count]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); QSet terrainTypes; terrainTypes << OsmAnd::ResourcesManager::ResourceType::SrtmMapRegion; terrainTypes << OsmAnd::ResourcesManager::ResourceType::HillshadeRegion; @@ -540,6 +633,9 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin }]; resourcesItems[OAExportSettingsType.TERRAIN_DATA] = sortedFiles; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG resources terrain duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + terrainFiles.count]]; // files = getFilesByType(localIndexInfoList, LocalIndexType.TTS_VOICE_DATA); // if (!files.isEmpty()) { @@ -550,6 +646,8 @@ - (void) exportSettings:(NSString *)fileDir fileName:(NSString *)fileName settin // resourcesItems.put(ExportSettingsType.VOICE, files); // } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG resources TOTAL duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - methodStartTime) * 1000]]; return resourcesItems; } diff --git a/Sources/Backup/OABackupDbHelper.m b/Sources/Backup/OABackupDbHelper.m index 4e2f601dd0..1717058006 100644 --- a/Sources/Backup/OABackupDbHelper.m +++ b/Sources/Backup/OABackupDbHelper.m @@ -7,6 +7,8 @@ // #import "OABackupDbHelper.h" +#import "OABackupHelper.h" +#import "OAOperationLog.h" #import @@ -105,6 +107,9 @@ @implementation OABackupDbHelper sqlite3 *backupFilesDB; dispatch_queue_t dbQueue; + + // COLLECT_LOCAL_DIAG: remove after cloud sync performance investigation. + OAOperationLog *_cloudSyncOperationLog; } + (OABackupDbHelper *)sharedDatabase @@ -130,6 +135,7 @@ - (instancetype)init [[NSFileManager defaultManager] createDirectoryAtPath:dir withIntermediateDirectories:YES attributes:nil error:nil]; dbQueue = dispatch_queue_create("backup_dbQueue", DISPATCH_QUEUE_SERIAL); + _cloudSyncOperationLog = [[OAOperationLog alloc] initWithOperationName:@"cloudSyncDatabase" debug:BACKUP_DEBUG_LOGS]; [self load]; } @@ -300,15 +306,22 @@ - (void) addUploadedFileInfo:(OAUploadedFileInfo *)info - (NSDictionary *) getUploadedFileInfoMap { + [_cloudSyncOperationLog startOperation:@"COLLECT_LOCAL_DIAG getUploadedFileInfoMap"]; + CFAbsoluteTime methodStartTime = CFAbsoluteTimeGetCurrent(); NSMutableDictionary *res = [NSMutableDictionary dictionary]; dispatch_sync(dbQueue, ^{ - + CFAbsoluteTime queueStartTime = CFAbsoluteTimeGetCurrent(); + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG dbQueue entered wait=%.3f ms", + (queueStartTime - methodStartTime) * 1000]]; + const char *dbpath = [_dbFilePath UTF8String]; sqlite3_stmt *statement; - + CFAbsoluteTime phaseStartTime = CFAbsoluteTimeGetCurrent(); if (sqlite3_open(dbpath, &backupFilesDB) == SQLITE_OK) { + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG sqlite_open END duration=%.3f ms success=1", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; NSString *querySQL = [NSString stringWithFormat:@"SELECT %@, %@, %@, %@ FROM %@", UPLOADED_FILE_COL_TYPE, UPLOADED_FILE_COL_NAME, @@ -316,8 +329,13 @@ - (void) addUploadedFileInfo:(OAUploadedFileInfo *)info UPLOADED_FILE_COL_MD5_DIGEST, UPLOADED_FILES_TABLE_NAME]; const char *query_stmt = [querySQL UTF8String]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); if (sqlite3_prepare_v2(backupFilesDB, query_stmt, -1, &statement, NULL) == SQLITE_OK) { + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG sqlite_prepare END duration=%.3f ms success=1", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); + NSInteger rowCount = 0; while (sqlite3_step(statement) == SQLITE_ROW) { NSString *type = [[NSString alloc] initWithUTF8String:(const char *) sqlite3_column_text(statement, 0)]; @@ -326,12 +344,32 @@ - (void) addUploadedFileInfo:(OAUploadedFileInfo *)info NSString *md5Digest = [[NSString alloc] initWithUTF8String:(const char *) sqlite3_column_text(statement, 3)]; OAUploadedFileInfo *info = [[OAUploadedFileInfo alloc] initWithType:type name:name uploadTime:uploadTime md5Digest:md5Digest]; res[[NSString stringWithFormat:@"%@___%@", info.type, info.name]] = info; + rowCount++; } + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG sqlite_rows END duration=%.3f ms rows=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + rowCount]]; sqlite3_finalize(statement); } + else + { + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG sqlite_prepare END duration=%.3f ms success=0 code=%d", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + sqlite3_errcode(backupFilesDB)]]; + } + phaseStartTime = CFAbsoluteTimeGetCurrent(); sqlite3_close(backupFilesDB); + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG sqlite_close END duration=%.3f ms", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000]]; + } + else + { + [_cloudSyncOperationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG sqlite_open END duration=%.3f ms success=0 code=%d", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + sqlite3_errcode(backupFilesDB)]]; } }); + [_cloudSyncOperationLog finishOperation:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG count=%ld", res.count]]; return res; } diff --git a/Sources/Backup/OACollectLocalFilesTask.m b/Sources/Backup/OACollectLocalFilesTask.m index 2ac3a86ec5..786ee55612 100644 --- a/Sources/Backup/OACollectLocalFilesTask.m +++ b/Sources/Backup/OACollectLocalFilesTask.m @@ -44,10 +44,24 @@ - (instancetype) initWithListener:(id)listener - (void) execute { + CFAbsoluteTime executeStartTime = CFAbsoluteTimeGetCurrent(); + [_operationLog log:@"COLLECT_LOCAL_DIAG execute BEGIN"]; dispatch_async(dispatch_get_global_queue(QOS_CLASS_USER_INITIATED, 0), ^{ - + [_operationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG worker BEGIN queueWait=%.3f ms", + (CFAbsoluteTimeGetCurrent() - executeStartTime) * 1000]]; + NSMutableArray *result = [NSMutableArray array]; + CFAbsoluteTime phaseStartTime = CFAbsoluteTimeGetCurrent(); + [_operationLog log:@"COLLECT_LOCAL_DIAG getUploadedFileInfoMap BEGIN"]; _infos = [_dbHelper getUploadedFileInfoMap]; + + [_operationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG getUploadedFileInfoMap END duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + _infos.count]]; + + phaseStartTime = CFAbsoluteTimeGetCurrent(); + [_operationLog log:@"COLLECT_LOCAL_DIAG getLocalItems BEGIN"]; + NSMutableDictionary *normalized = [NSMutableDictionary dictionaryWithCapacity:_infos.count]; [_infos enumerateKeysAndObjectsUsingBlock:^(NSString *key, OAUploadedFileInfo *info, BOOL *stop) { NSString *decomposedKey = key.decomposedStringWithCanonicalMapping; @@ -56,9 +70,15 @@ - (void) execute normalized[decomposedKey] = info; }]; _infos = normalized; + NSArray *localItems = [self getLocalItems]; + [_operationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG getLocalItems END duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + localItems.count]]; NSFileManager *fileManager = NSFileManager.defaultManager; [_operationLog log:@"getLocalItems"]; + phaseStartTime = CFAbsoluteTimeGetCurrent(); + [_operationLog log:@"COLLECT_LOCAL_DIAG createLocalFiles loop BEGIN"]; for (OASettingsItem *item in localItems) { NSString *fileName = [BackupUtils getItemFileName:item]; @@ -158,6 +178,9 @@ - (void) execute lastModified:item.lastModifiedTime]; } } + [_operationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG createLocalFiles loop END duration=%.3f ms files=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + result.count]]; dispatch_async(dispatch_get_main_queue(), ^{ [_operationLog finishOperation:[NSString stringWithFormat:@"Files=%ld", result.count]]; if (_listener) @@ -193,7 +216,15 @@ - (void) createLocalFile:(NSMutableArray *)result item:(OASetting && lastMd5.length > 0; if (needM5Digest && filePath && [NSFileManager.defaultManager fileExistsAtPath:filePath]) { + CFAbsoluteTime md5StartTime = CFAbsoluteTimeGetCurrent(); NSString *md5 = [OAUtilities fileMD5:filePath]; + CFAbsoluteTime md5DurationMs = (CFAbsoluteTimeGetCurrent() - md5StartTime) * 1000; + if (md5DurationMs >= 50) + { + [_operationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG slow fileMD5 duration=%.3f ms file=%@", + md5DurationMs, + fileName]]; + } if ([md5 isEqualToString:lastMd5]) { item.localModifiedTime = localFile.uploadTime; @@ -208,8 +239,18 @@ - (void) createLocalFile:(NSMutableArray *)result item:(OASetting - (NSArray *) getLocalItems { + CFAbsoluteTime phaseStartTime = CFAbsoluteTimeGetCurrent(); NSArray *types = [self getEnabledExportTypes]; - return [OASettingsHelper.sharedInstance getFilteredSettingsItems:types addProfiles:YES doExport:YES]; + [_operationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG getEnabledExportTypes END duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + types.count]]; + + phaseStartTime = CFAbsoluteTimeGetCurrent(); + NSArray *items = [OASettingsHelper.sharedInstance getFilteredSettingsItems:types addProfiles:YES doExport:YES]; + [_operationLog log:[NSString stringWithFormat:@"COLLECT_LOCAL_DIAG getFilteredSettingsItems END duration=%.3f ms count=%ld", + (CFAbsoluteTimeGetCurrent() - phaseStartTime) * 1000, + items.count]]; + return items; } - (NSArray *)getEnabledExportTypes