[mob][photos] Last logging todos

mobile/lib/services/isolate_functions.dart

@@ -57,7 +57,6 @@ Future<dynamic> isolateFunction(
       final modelPaths = args['modelPaths'] as List<String>;
       final addresses = <int>[];
       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<dynamic> isolateFunction(
 
     /// MLIndexingIsolate
     case IsolateOperation.releaseIndexingModels:
-      // TODO:lau check logging here
       final modelNames = args['modelNames'] as List<String>;
       final modelAddresses = args['modelAddresses'] as List<int>;
       for (int i = 0; i < modelNames.length; i++) {
@@ -114,7 +112,6 @@ Future<dynamic> isolateFunction(
 
     /// MLComputer
     case IsolateOperation.runClipText:
-      //TODO:lau check logging here
       final textEmbedding = await ClipTextEncoder.predict(args);
       return List<double>.from(textEmbedding, growable: false);
 

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<void> 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.");
     }
   }

mobile/lib/services/machine_learning/semantic_search/clip/clip_text_encoder.dart

@@ -34,14 +34,25 @@ class ClipTextEncoder extends MlModel {
   static Future<List<double>> predict(Map args) async {
     final text = args["text"] as String;
     final address = args["address"] as int;
+    final startTime = DateTime.now();
     final List<int> tokenize = await ClipTextTokenizer.instance.tokenize(text);
     final int32list = Int32List.fromList(tokenize);
+    final tokenizeTime = DateTime.now();
+    final tokenizeMs = tokenizeTime.difference(startTime).inMilliseconds;
     try {
+      late List<double> 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})",

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;
   }
 

mobile/lib/utils/image_ml_util.dart

@@ -109,10 +109,9 @@ Future<List<Uint8List>> generateFaceThumbnailsUsingCanvas(
   Uint8List imageData,
   List<FaceBox> 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 = <Future<Uint8List>>[];
     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<List<Uint8List>> generateFaceThumbnailsUsingCanvas(
     final List<Uint8List> 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<AlignmentResult>, List<bool>, List<double>, Size)>
   int width = 112,
   int height = 112,
 }) async {
-
   final Size originalSize =
       Size(image.width.toDouble(), image.height.toDouble());