From 9dadb92d8d059f35ad66db063d16b47b3eb04fdd Mon Sep 17 00:00:00 2001 From: laurenspriem Date: Tue, 3 Sep 2024 12:49:45 +0200 Subject: [PATCH] [mob][photos] Last logging todos --- mobile/lib/services/isolate_functions.dart | 3 - .../services/machine_learning/ml_model.dart | 60 ++++++++++++------- .../clip/clip_text_encoder.dart | 15 ++++- .../clip/clip_text_tokenizer.dart | 4 ++ mobile/lib/utils/image_ml_util.dart | 15 ++--- 5 files changed, 62 insertions(+), 35 deletions(-) diff --git a/mobile/lib/services/isolate_functions.dart b/mobile/lib/services/isolate_functions.dart index e660351666..08624ef206 100644 --- a/mobile/lib/services/isolate_functions.dart +++ b/mobile/lib/services/isolate_functions.dart @@ -57,7 +57,6 @@ Future isolateFunction( final modelPaths = args['modelPaths'] as List; final addresses = []; for (int i = 0; i < modelNames.length; i++) { - // TODO:lau check logging here final int address = await MlModel.loadModel( modelNames[i], modelPaths[i], @@ -68,7 +67,6 @@ Future isolateFunction( /// MLIndexingIsolate case IsolateOperation.releaseIndexingModels: - // TODO:lau check logging here final modelNames = args['modelNames'] as List; final modelAddresses = args['modelAddresses'] as List; for (int i = 0; i < modelNames.length; i++) { @@ -114,7 +112,6 @@ Future isolateFunction( /// MLComputer case IsolateOperation.runClipText: - //TODO:lau check logging here final textEmbedding = await ClipTextEncoder.predict(args); return List.from(textEmbedding, growable: false); diff --git a/mobile/lib/services/machine_learning/ml_model.dart b/mobile/lib/services/machine_learning/ml_model.dart index a3a05e5f14..ec91f0a0df 100644 --- a/mobile/lib/services/machine_learning/ml_model.dart +++ b/mobile/lib/services/machine_learning/ml_model.dart @@ -9,7 +9,7 @@ import "package:photos/utils/network_util.dart"; import "package:synchronized/synchronized.dart"; abstract class MlModel { - static final Logger isolateLogger = Logger("MlModelInIsolate"); + static final Logger isolateLogger = Logger("MlModel"); Logger get logger; String get kModelBucketEndpoint => "https://models.ente.io/"; @@ -95,10 +95,28 @@ abstract class MlModel { String modelName, String modelPath, ) async { - if (usePlatformPlugin) { - return await _loadModelWithPlatformPlugin(modelName, modelPath); - } else { - return await _loadModelWithFFI(modelName, modelPath); + isolateLogger + .info('Start loading $modelName (platformPlugin: $usePlatformPlugin)'); + final time = DateTime.now(); + try { + late int result; + if (usePlatformPlugin) { + result = await _loadModelWithPlatformPlugin(modelName, modelPath); + } else { + result = await _loadModelWithFFI(modelName, modelPath); + } + final timeMs = DateTime.now().difference(time).inMilliseconds; + isolateLogger.info( + "$modelName model loaded in $timeMs ms (platformPlugin: $usePlatformPlugin)", + ); + return result; + } catch (e, s) { + isolateLogger.severe( + "Failed to load model $modelName (platformPlugin: $usePlatformPlugin)", + e, + s, + ); + rethrow; } } @@ -106,18 +124,12 @@ abstract class MlModel { String modelName, String modelPath, ) async { - final startTime = DateTime.now(); - isolateLogger.info('Initializing $modelName with EntePlugin'); final OnnxDart plugin = OnnxDart(); final bool? initResult = await plugin.init(modelName, modelPath); if (initResult == null || !initResult) { isolateLogger.severe("Failed to initialize $modelName with EntePlugin."); throw Exception("Failed to initialize $modelName with EntePlugin."); } - final endTime = DateTime.now(); - isolateLogger.info( - "$modelName loaded via EntePlugin in ${endTime.difference(startTime).inMilliseconds}ms", - ); return 0; } @@ -125,10 +137,8 @@ abstract class MlModel { String modelName, String modelPath, ) async { - isolateLogger.info('Initializing $modelName with FFI'); ONNXEnvFFI.instance.initONNX(modelName); try { - final startTime = DateTime.now(); final sessionOptions = OrtSessionOptions() ..setInterOpNumThreads(1) ..setIntraOpNumThreads(1) @@ -136,21 +146,26 @@ abstract class MlModel { GraphOptimizationLevel.ortEnableAll, ); final session = OrtSession.fromFile(File(modelPath), sessionOptions); - final endTime = DateTime.now(); - isolateLogger.info( - "$modelName loaded with FFI, took: ${endTime.difference(startTime).inMilliseconds}ms", - ); return session.address; - } catch (e) { + } catch (e, s) { + isolateLogger.severe("Failed to load model $modelName with FFI", e, s); rethrow; } } static Future releaseModel(String modelName, int sessionAddress) async { - if (usePlatformPlugin) { - await _releaseModelWithPlatformPlugin(modelName); - } else { - await _releaseModelWithFFI(modelName, sessionAddress); + try { + if (usePlatformPlugin) { + await _releaseModelWithPlatformPlugin(modelName); + } else { + await _releaseModelWithFFI(modelName, sessionAddress); + } + } catch (e, s) { + isolateLogger.severe( + "Failed to release model $modelName (platformPlugin: $usePlatformPlugin)", + e, + s, + ); } } @@ -158,7 +173,6 @@ abstract class MlModel { final OnnxDart plugin = OnnxDart(); final bool? initResult = await plugin.release(modelName); if (initResult == null || !initResult) { - isolateLogger.severe("Failed to release $modelName with PlatformPlugin."); throw Exception("Failed to release $modelName with PlatformPlugin."); } } diff --git a/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_encoder.dart b/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_encoder.dart index 8a50b785f1..792b20fed8 100644 --- a/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_encoder.dart +++ b/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_encoder.dart @@ -34,14 +34,25 @@ class ClipTextEncoder extends MlModel { static Future> predict(Map args) async { final text = args["text"] as String; final address = args["address"] as int; + final startTime = DateTime.now(); final List tokenize = await ClipTextTokenizer.instance.tokenize(text); final int32list = Int32List.fromList(tokenize); + final tokenizeTime = DateTime.now(); + final tokenizeMs = tokenizeTime.difference(startTime).inMilliseconds; try { + late List embedding; if (MlModel.usePlatformPlugin) { - return await _runPlatformPluginPredict(int32list); + embedding = await _runPlatformPluginPredict(int32list); } else { - return _runFFIBasedPredict(int32list, address); + embedding = _runFFIBasedPredict(int32list, address); } + final inferTime = DateTime.now(); + final inferMs = inferTime.difference(tokenizeTime).inMilliseconds; + final totalMs = inferTime.difference(startTime).inMilliseconds; + _logger.info( + "Clip text predict took $totalMs ms (predict: $inferMs ms, tokenize: $tokenizeMs ms) for text: '$text'", + ); + return embedding; } catch (e, s) { _logger.severe( "Clip text inference failed (PlatformPlugin: ${MlModel.usePlatformPlugin})", diff --git a/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_tokenizer.dart b/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_tokenizer.dart index 7ac5c7950d..7bb4e1a0c2 100644 --- a/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_tokenizer.dart +++ b/mobile/lib/services/machine_learning/semantic_search/clip/clip_text_tokenizer.dart @@ -3,9 +3,12 @@ import "dart:io" show File; import "dart:math"; import "package:html_unescape/html_unescape.dart"; +import "package:logging/logging.dart"; import "package:tuple/tuple.dart"; class ClipTextTokenizer { + final _logger = Logger("ClipTextTokenizer"); + static const int totalTokens = 77; late String vocabulary; @@ -75,6 +78,7 @@ class ClipTextTokenizer { sot = encoder['<|startoftext|>']!; eot = encoder['<|endoftext|>']!; + _logger.info("Clip text tokenizer initialized"); _isInitialized = true; } diff --git a/mobile/lib/utils/image_ml_util.dart b/mobile/lib/utils/image_ml_util.dart index 9b68ca9b3a..f2224d2b4b 100644 --- a/mobile/lib/utils/image_ml_util.dart +++ b/mobile/lib/utils/image_ml_util.dart @@ -109,10 +109,9 @@ Future> generateFaceThumbnailsUsingCanvas( Uint8List imageData, List faceBoxes, ) async { - final Image img = await decodeImageFromData(imageData); - int i = 0; - + int i = 0; // Index of the faceBox, initialized here for logging purposes try { + final Image img = await decodeImageFromData(imageData); final futureFaceThumbnails = >[]; for (final faceBox in faceBoxes) { // Note that the faceBox values are relative to the image size, so we need to convert them to absolute values first @@ -153,9 +152,12 @@ Future> generateFaceThumbnailsUsingCanvas( final List faceThumbnails = await Future.wait(futureFaceThumbnails); return faceThumbnails; - } catch (e) { - _logger.severe('Error generating face thumbnails: $e'); - _logger.severe('cropImage problematic input argument: ${faceBoxes[i]}'); + } catch (e, s) { + _logger.severe( + 'Error generating face thumbnails. cropImage problematic input argument: ${faceBoxes[i]}', + e, + s, + ); return []; } } @@ -259,7 +261,6 @@ Future<(Float32List, List, List, List, Size)> int width = 112, int height = 112, }) async { - final Size originalSize = Size(image.width.toDouble(), image.height.toDouble());