fix issues with background operations implementation, added more logging

src/KeePassLib2Android/Kp2aLog.cs

@@ -21,6 +21,7 @@ using System.IO;
 using Android;
 using Android.App;
 using Android.Content;
+using Android.OS;
 using Android.Preferences;
 using KeePassLib.Serialization;
 
@@ -35,7 +36,15 @@ namespace keepass2android
 		public static void Log(string message)
 		{
             if (message != null)
+            {
+                message += Thread.CurrentThread.ManagedThreadId != 0
+                    ? " (Thread ID: " + Thread.CurrentThread.ManagedThreadId + ")"
+                    : "";
+                if (Looper.MainLooper == Looper.MyLooper())
+                    message += " (Main Looper)";
                 Android.Util.Log.Debug("KP2A", message);
+            }
+
             if (LogToFile)
 			{
 				lock (_fileLocker)

src/KeePassLib2Android/Serialization/KdbxFile.Read.Streamed.cs

@@ -208,7 +208,7 @@ namespace KeePassLib.Serialization
 						if (!string.IsNullOrEmpty(strHash) && (m_pbHashOfHeader != null) &&
 							!m_bRepairMode)
 						{
-							Debug.Assert(m_uFileVersion < FileVersion32_4);
+						//	Debug.Assert(m_uFileVersion < FileVersion32_4);
 
 							byte[] pbHash = Convert.FromBase64String(strHash);
 							if (!MemUtil.ArraysEqual(pbHash, m_pbHashOfHeader))

src/KeePassLib2Android/Serialization/KdbxFile.Read.cs

@@ -488,7 +488,7 @@ namespace KeePassLib.Serialization
 
 					ProtectedBinary pb = new ProtectedBinary(bProt, pbData,
 						1, pbData.Length - 1);
-					Debug.Assert(m_pbsBinaries.Find(pb) < 0); // No deduplication?
+					//Debug.Assert(m_pbsBinaries.Find(pb) < 0); // No deduplication?
 					m_pbsBinaries.Add(pb);
 
 					if (bProt) MemUtil.ZeroByteArray(pbData);

src/Kp2aBusinessLogic/OperationRunner.cs

@@ -1,6 +1,7 @@
 using Android.App;
 using Android.Content;
 using Android.OS;
+using System.Threading.Tasks;
 using Thread = Java.Lang.Thread;
 
 namespace keepass2android;
@@ -59,10 +60,11 @@ public class OperationRunner
 
     public void Run(IKp2aApp app, OperationWithFinishHandler operation, bool runBlocking = false)
     {
+        Kp2aLog.Log("OPR: Run: " + operation.GetType().Name + ", runBlocking: " + runBlocking);
         lock (Instance._taskQueueLock)
         {
             _taskQueue.Enqueue(new OperationWithMetadata(){ Operation = operation, RunBlocking = runBlocking});
-            SetNewActiveContext(app);
+            operation.SetStatusLogger(_statusLogger);
 
             // Start thread to run the task (unless it's already running)
             if (_thread == null)
@@ -79,6 +81,7 @@ public class OperationRunner
                             {
                                 _thread = null;
                                 _statusLogger.EndLogging();
+                                Kp2aLog.Log("OPR: task queue empty. Stopping operation runner thread.");
                                 break;
                             }
                             else
@@ -89,21 +92,38 @@ public class OperationRunner
 
                         if (_currentlyRunningTask.Value.RunBlocking)
                         {
-                            app.UiThreadHandler.Post(() => TrySetupProgressDialog());
+                            Kp2aLog.Log("OPR: Run. Posting to set up progress dialog for blocking task: " + _currentlyRunningTask?.Operation?.GetType()?.Name ?? "null");
+                            app.UiThreadHandler.Post(
+                                () =>
+                                {
+                                    Kp2aLog.Log("OPR: Run. Starting Setting up progress dialog for blocking task: " + _currentlyRunningTask?.Operation?.GetType()?.Name ?? "null");
+                                    TrySetupProgressDialog();
+                                    Kp2aLog.Log("OPR: Run. Finished Setting up progress dialog for blocking task: " + _currentlyRunningTask?.Operation?.GetType()?.Name ?? "null");
+                                });
                         }
 
                         var originalFinishedHandler = _currentlyRunningTask.Value.Operation.operationFinishedHandler;
                         _currentlyRunningTask.Value.Operation.operationFinishedHandler = new ActionOnOperationFinished(app, (
                             (success, message, context) =>
                             {
-                                if (_currentlyRunningTask.Value.RunBlocking)
+                                if (_currentlyRunningTask?.RunBlocking == true)
                                 {
+                                    Kp2aLog.Log("OPR: Run. Blocking task finished: " + _currentlyRunningTask?.Operation?.GetType()?.Name ?? "null");
+                                    _app.UiThreadHandler.Post(() =>
+                                    {
+                                        Kp2aLog.Log("OPR: Starting Dismissing progress dialog");
                                         _progressDialog?.Dismiss();
+                                        Kp2aLog.Log("OPR: Finished Dismissing progress dialog");
                                     }
+                                        );
+                                }
+                                Kp2aLog.Log("OPR: Run. Finished handler called for task: " + _currentlyRunningTask?.Operation?.GetType()?.Name ?? "null");
                                 _currentlyRunningTask = null;
 
                             }), originalFinishedHandler);
+                        Kp2aLog.Log("OPR: starting to run " + _currentlyRunningTask?.Operation?.GetType()?.Name ?? "null");
                         _currentlyRunningTask.Value.Operation.Run();
+                        
                         while (_currentlyRunningTask != null)
                         {
                             try
@@ -115,11 +135,14 @@ public class OperationRunner
                                 Kp2aLog.Log("Thread interrupted.");
                             }
                         }
+                        Kp2aLog.Log("OPR: waiting for next task in queue...");
                     }
 
                 });
                 _thread.Start();
             }
+            else Kp2aLog.Log("OPR: thread already running, only enqueued " + operation.GetType().Name );
+
 
         }
                
@@ -128,6 +151,7 @@ public class OperationRunner
 
     private bool TrySetupProgressDialog()
     {
+        Kp2aLog.Log("OPR: TrySetupProgressDialog");
         string currentMessage = "Initializing...";
         string currentSubmessage = "";
 
@@ -142,7 +166,9 @@ public class OperationRunner
             var pd = _progressDialog;
             _app.UiThreadHandler.Post(() =>
             {
+                Kp2aLog.Log("OPR: Starting TrySetupProgressDialog: Dismissing existing progress dialog");
                 pd.Dismiss();
+                Kp2aLog.Log("OPR: Finished TrySetupProgressDialog: Dismissing existing progress dialog");
             });
         }
 
@@ -150,7 +176,7 @@ public class OperationRunner
         _progressDialog = _app.CreateProgressDialog(_app.ActiveContext);
         if (_progressDialog == null)
         {
-            Kp2aLog.Log("OperationRunner.TrySetupProgressDialog: _progressDialog is null");
+            Kp2aLog.Log("OPR: OperationRunner.TrySetupProgressDialog: _progressDialog is null");
             return false;
         }
     
@@ -164,9 +190,9 @@ public class OperationRunner
         return true;
     }
 
-
     public void SetNewActiveContext(IKp2aApp app)
     {
+        Kp2aLog.Log("OPR: SetNewActiveContext: " + app.ActiveContext?.GetType().Name);
         _app = app;
         Context? context = app.ActiveContext;
         bool isAppContext = context == null || (context.ApplicationContext == context);
@@ -179,9 +205,15 @@ public class OperationRunner
                 return;
             }
 
-            if (_currentlyRunningTask?.RunBlocking == true)
+            if (_currentlyRunningTask?.RunBlocking == true && (context is Activity { IsFinishing: false, IsDestroyed:false}))
             {
-                app.UiThreadHandler.Post(() => TrySetupProgressDialog());
+                Kp2aLog.Log("OPR: SetNewActiveContext: running blocking task, setting up progress dialog");
+                app.UiThreadHandler.Post(() =>
+                {
+                    Kp2aLog.Log("OPR: Starting posted TrySetupProgressDialog");
+                    TrySetupProgressDialog();
+                    Kp2aLog.Log("OPR: Finished posted TrySetupProgressDialog");
+                });
             }
             else
             {

src/Kp2aBusinessLogic/ProgressDialogStatusLogger.cs

@@ -121,6 +121,7 @@ namespace keepass2android
             {
                 _handler.Post(() =>
                     {
+                        Kp2aLog.Log("OPR: Starting posted SetMessage");
                         if (!String.IsNullOrEmpty(submessage))
                         {
                             _progressDialog.SetMessage(_message + " (" + submessage + ")");
@@ -129,6 +130,7 @@ namespace keepass2android
                         {
                             _progressDialog.SetMessage(_message);
                         }
+                        Kp2aLog.Log("OPR: Finished posted SetMessage");
                     }
                 );
             }
@@ -138,8 +140,9 @@ namespace keepass2android
         {
             _handler.Post(() =>
             {
-                
+                Kp2aLog.Log("OPR: Starting posted Show");
                 _progressDialog?.Show();
+                Kp2aLog.Log("OPR: Finished posted Show");
 
             });
         }
@@ -148,8 +151,9 @@ namespace keepass2android
         {
             _handler.Post(() =>
             {
-                
+                Kp2aLog.Log("OPR: Starting posted Dismiss");
                 _progressDialog?.Dismiss();
+                Kp2aLog.Log("OPR: Finished posted Dismiss");
 
             });
         }
@@ -160,7 +164,12 @@ namespace keepass2android
             _message = message;
             if (_app != null && _progressDialog != null && _handler != null)
             {
-                _handler.Post(() => { _progressDialog.SetMessage(message); });
+                _handler.Post(() =>
+                {
+                    Kp2aLog.Log("OPR: Starting posted SetMessage");
+                    _progressDialog.SetMessage(message);
+                    Kp2aLog.Log("OPR: Finishing posted SetMessage");
+                });
             }
         }
 

src/Kp2aBusinessLogic/database/SynchronizeCachedDatabase.cs

@@ -66,12 +66,12 @@ namespace keepass2android
                 var baseVersionHash = cachingFileStorage.GetBaseVersionHash(ioc);
                 Kp2aLog.Log("Checking for file change. baseVersionHash = " + baseVersionHash);
                 if (baseVersionHash != hash ||
-                    false //TODO remove
+                    true //TODO remove
                    )
                 {
                     //remote file is modified
                     if (cachingFileStorage.HasLocalChanges(ioc)
-                        || false //TODO remove
+                        || true //TODO remove
                        )
                     {
                         //conflict! need to merge

src/Kp2aBusinessLogic/database/edit/ActionOnOperationFinished.cs

@@ -45,10 +45,17 @@ namespace keepass2android
 				Message = "";
 			if (Handler != null)
 			{
-				Handler.Post(() => {_actionToPerform(Success, Message, ActiveContext);});
+				Handler.Post(() =>
+                {
+                    Kp2aLog.Log("OPR: Starting posted actionToPerform ");
+                    _actionToPerform(Success, Message, ActiveContext);
+                    Kp2aLog.Log("OPR: Finished posted actionToPerform ");
+                });
 			}
             else
+            {
                 _actionToPerform(Success, Message, ActiveContext);
+            }
 			base.Run();
 		}
 	}
@@ -80,7 +87,7 @@ namespace keepass2android
             {
                 _app.RegisterPendingActionForContextInstance(_contextInstanceId, this);
             }
-            else base.Run();
+            else _app.UiThreadHandler.Post(() => base.Run());
         }
 
     }

src/Kp2aBusinessLogic/database/edit/OnOperationFinishedHandler.cs

@@ -98,8 +98,15 @@ namespace keepass2android
 			// Pass on result on call finish
 			NextOnOperationFinishedHandler.SetResult(Success, Message, ImportantMessage, Exception);
 
-			if ( Handler != null ) {
+            var handler = Handler ?? NextOnOperationFinishedHandler.Handler ?? null;
-				Handler.Post(NextOnOperationFinishedHandler.Run); 
+
+            if (handler != null ) {
+                handler.Post(() =>
+                {
+                    Kp2aLog.Log("OPR: Starting posted NextOnOperationFinishedHandler");
+                    NextOnOperationFinishedHandler.Run();
+                    Kp2aLog.Log("OPR: Finished posted NextOnOperationFinishedHandler");
+                }); 
 			} else {
 				NextOnOperationFinishedHandler.Run();
 			}

src/keepass2android-app/LifecycleAwareActivity.cs

@@ -104,8 +104,6 @@ namespace keepass2android
         protected override void OnStart()
         {
             App.Kp2a.ActiveContext = this;
-            OperationRunner.Instance.SetNewActiveContext( App.Kp2a);
-            
             base.OnStart();
             Kp2aLog.Log(ClassName + ".OnStart" + " " + ID);
         }

src/keepass2android-app/SyncUtil.cs

@@ -56,7 +56,7 @@ namespace keepass2android
             OperationWithFinishHandler task;
             OnOperationFinishedHandler onOperationFinishedHandler = new ActionInContextInstanceOnOperationFinished(_activity.ContextInstanceId, App.Kp2a, (success, message, context) =>
             {
-                new Handler(Looper.MainLooper).Post(() =>
+                App.Kp2a.UiThreadHandler.Post(() =>
                 {
                     if (!String.IsNullOrEmpty(message))
                         App.Kp2a.ShowMessage(context, message, success ? MessageSeverity.Info : MessageSeverity.Error);

src/keepass2android-app/app/App.cs

@@ -651,12 +651,18 @@ namespace keepass2android
             {
                 if (app.ActiveContext is Activity activity)
                 {
-                    Handler handler = new Handler(Looper.MainLooper);
+                    Kp2aLog.Log("OPR: Will show YesNoCancel dialog because active context is an Activity.");
-                    handler.Post(() =>
+                
-                    {
                     if (_dialog is { IsShowing: true })
+                    {
+                        try
                         {
                             _dialog.Dismiss();
+                        }
+                        catch (Exception e)
+                        {
+                            Kp2aLog.LogUnexpectedError(e);
+                        }
                         _dialog = null;
                     }
 
@@ -711,6 +717,11 @@ namespace keepass2android
                             DismissHandler(_dialog, EventArgs.Empty);
                         }));
                     }
+                    else
+                    {
+                        _dialog.SetCancelable(false);
+                    }
+                    
 
                     onUserInputDialogShow();
                     try
@@ -737,11 +748,11 @@ namespace keepass2android
                         }
 
                     }
-                    });
                     return true;
                 }
                 else
                 {
+                    Kp2aLog.Log("OPR: Cannot show YesNoCancel dialog because active context is not an Activity.");
 					OperationRunner.Instance.StatusLogger?.UpdateSubMessage(App.Context.GetString(Resource.String.user_interaction_required));
                     return false;
                 }
@@ -759,6 +770,7 @@ namespace keepass2android
             {
                 throw new Java.Lang.InterruptedException();
             }
+			Kp2aLog.Log("OPR: AskYesNoCancel called with titleKey " + titleKey + ", messageKey " + messageKey);
 
             _currentlyPendingYesNoCancelQuestion = new YesNoCancelQuestion()
             {
@@ -773,7 +785,12 @@ namespace keepass2android
                 MessageSuffix = messageSuffix
             };
             
+            UiThreadHandler.Post( () =>
+            {
+                Kp2aLog.Log("OPR: Starting posted AskYesNoCancel/TryShow ");
                 _currentlyPendingYesNoCancelQuestion.TryShow(this, OnUserInputDialogClose, OnUserInputDialogShow);
+                Kp2aLog.Log("OPR: Finished posted AskYesNoCancel/TryShow ");
+            });
                     
 		}
 
@@ -786,16 +803,20 @@ namespace keepass2android
 		/// </summary>
 		private void ShowAllActiveProgressDialogs()
         {
+            Kp2aLog.Log("OPR: ShowAllActiveProgressDialogs");
 			foreach (RealProgressDialog progressDialog in _activeProgressDialogs)
 			{
+                Kp2aLog.Log("OPR: ShowAllActiveProgressDialogs: Showing " + progressDialog.GetType().Name);
                 progressDialog.Show();
 			}
 		}
 
 		private void HideAllActiveProgressDialogs()
 		{
+            Kp2aLog.Log("OPR: HideAllActiveProgressDialogs");
             foreach (RealProgressDialog progressDialog in _activeProgressDialogs)
 			{
+                Kp2aLog.Log("OPR: HideAllActiveProgressDialogs: Hiding " + progressDialog.GetType().Name);
                 progressDialog.Hide();
 			}
 		}
@@ -816,6 +837,7 @@ namespace keepass2android
 		private void OnUserInputDialogClose()
 		{
 			_isShowingUserInputDialog = false;
+			Kp2aLog.Log("OPR: OnUserInputDialogClose called, _currentlyPendingYesNoCancelQuestion is " + (_currentlyPendingYesNoCancelQuestion != null ? "not null" : "null") + " Will set to null now.");
             _currentlyPendingYesNoCancelQuestion = null;
 
             ShowAllActiveProgressDialogs();
@@ -870,8 +892,17 @@ namespace keepass2android
 				// Only show if asking dialog not also showing
 				if (!_app._isShowingUserInputDialog)
 				{
+                    Kp2aLog.Log("OPR: Showing progress dialog " + _pd.GetType().Name);
+
+                    try
+                    {
                         _pd.Show();
                     }
+                    catch (Exception e)
+                    {
+                        Kp2aLog.LogUnexpectedError(e);
+                    }
+				}
 			}
 
 			public void Hide()
@@ -882,6 +913,7 @@ namespace keepass2android
 
         public IProgressDialog CreateProgressDialog(Context ctx)
         {
+            Kp2aLog.Log("OPR: CreateProgressDialog called with ctx " + ctx?.GetType().Name);
             /*Kp2aLog.Log("ctx is null ? " + (ctx == null));
             Kp2aLog.Log("ctx is activity ? " + (ctx is Activity));
             Kp2aLog.Log("ctx is destroyed ? " + (ctx is Activity { IsDestroyed: true }));
@@ -898,6 +930,7 @@ namespace keepass2android
             catch (Exception e)
             {
                 //may happen if the activity is (being) destroyed
+                Kp2aLog.Log("OPR: CreateProgressDialog failed with " + e.ToString());
                 return null;
             }
 
@@ -1306,6 +1339,8 @@ namespace keepass2android
 
         public void StartBackgroundSyncService()
         {
+            Kp2aLog.Log("OPR: StartBackgroundSyncService");
+
            Intent intent = new Intent(App.Context, typeof(BackgroundSyncService));
             intent.SetAction(BackgroundSyncService.ActionStart);
             App.Context.StartService(intent);
@@ -1505,7 +1540,9 @@ namespace keepass2android
             set
             {
                 _activeContext = value;
-                _currentlyPendingYesNoCancelQuestion?.TryShow(this, OnUserInputDialogClose, OnUserInputDialogClose);
+                OperationRunner.Instance.SetNewActiveContext(App.Kp2a);
+                Kp2aLog.Log("OPR: ActiveContext set to " + _activeContext?.GetType().Name + ". Pending question? " +(_currentlyPendingYesNoCancelQuestion != null));
+                _currentlyPendingYesNoCancelQuestion?.TryShow(this, OnUserInputDialogClose, OnUserInputDialogShow);
             }
         }
 
@@ -1650,9 +1687,6 @@ namespace keepass2android
         {
             Kp2aLog.Log("Going to background");
             Kp2a.ActiveContext = null;
-			// notify background operation runner that there is currently no active context, i.e. no UI where status can be displayed.
-			// The OperationRunner will launch the background sync service if a task (even a blocking one) is running currently.
-            OperationRunner.Instance.SetNewActiveContext(Kp2a);
 
         }
 

src/keepass2android-app/services/BackgroundSyncService.cs

@@ -52,7 +52,6 @@ namespace keepass2android.services
                 CreateNotificationChannel();
                 StartForeground(NotificationId, BuildNotification());
                 App.Kp2a.ActiveContext = this;
-                OperationRunner.Instance.SetNewActiveContext(App.Kp2a);
                 return StartCommandResult.Sticky;
             }
             catch (Exception ex)

src/keepass2android-app/views/BackgroundOperationContainer.cs

@@ -42,29 +42,34 @@ public class BackgroundOperationContainer : LinearLayout, IProgressUi
 
     public void Show()
     {
-        new Handler(Looper.MainLooper).Post(() =>
+        App.Kp2a.UiThreadHandler.Post(() =>
         {
+            Kp2aLog.Log("OPR: Starting posted Show ");
             Visibility = ViewStates.Visible;
             FindViewById<TextView>(Resource.Id.background_ops_message)!.Visibility = ViewStates.Gone;
             FindViewById<TextView>(Resource.Id.background_ops_submessage)!.Visibility = ViewStates.Gone;
+            Kp2aLog.Log("OPR: Finished posted Show ");
         });
 
     }
 
     public void Hide()
     {
-        new Handler(Looper.MainLooper).Post(() =>
+        App.Kp2a.UiThreadHandler.Post(() =>
         {
+            Kp2aLog.Log("OPR: Starting posted Hide ");
             String activityType = Context.GetType().FullName;
             Kp2aLog.Log("Hiding background ops container in" + activityType);
             Visibility = ViewStates.Gone;
+            Kp2aLog.Log("OPR: Finished posted Hide ");
         });
     }
 
     public void UpdateMessage(string message)
     {
-        new Handler(Looper.MainLooper).Post(() =>
+        App.Kp2a.UiThreadHandler.Post(() =>
         {
+            Kp2aLog.Log("OPR: Starting posted UpdateMessage ");
             TextView messageTextView = FindViewById<TextView>(Resource.Id.background_ops_message)!;
             if (string.IsNullOrEmpty(message))
             {
@@ -75,13 +80,15 @@ public class BackgroundOperationContainer : LinearLayout, IProgressUi
                 messageTextView.Visibility = ViewStates.Visible;
                 messageTextView.Text = message;
             }
+            Kp2aLog.Log("OPR: Finished posted UpdateMessage ");
         });
     }
 
     public void UpdateSubMessage(string submessage)
     {
-        new Handler(Looper.MainLooper).Post(() =>
+        App.Kp2a.UiThreadHandler.Post(() =>
         {
+            Kp2aLog.Log("OPR: Starting posted UpdateSubMessage ");
             TextView subMessageTextView = FindViewById<TextView>(Resource.Id.background_ops_submessage)!;
             if (string.IsNullOrEmpty(submessage))
             {
@@ -92,6 +99,7 @@ public class BackgroundOperationContainer : LinearLayout, IProgressUi
                 subMessageTextView.Visibility = ViewStates.Visible;
                 subMessageTextView.Text = submessage;
             }
+            Kp2aLog.Log("OPR: Finished posted UpdateSubMessage ");
         });
     }
 }

src/keepass2android-app/views/PwEntryView.cs

@@ -125,9 +125,12 @@ namespace keepass2android.view
 
             if (_groupBaseActivity.IsFinishing)
                 return;
-
             _entry = pw;
             _pos = pos;
+            try
+            {
+
+                
                 ev.FindViewById(Resource.Id.icon).Visibility = ViewStates.Visible;
                 ev.FindViewById(Resource.Id.check_mark).Visibility = ViewStates.Invisible;
 
@@ -138,7 +141,8 @@ namespace keepass2android.view
                 if (isExpired)
                 {
                     _db.DrawableFactory.AssignDrawableTo(iv, Context, _db.KpDatabase, PwIcon.Expired, PwUuid.Zero, false);
-			} else
+                }
+                else
                 {
                     _db.DrawableFactory.AssignDrawableTo(iv, Context, _db.KpDatabase, pw.IconId, pw.CustomIconUuid, false);
                 }
@@ -184,11 +188,13 @@ namespace keepass2android.view
                     _textviewDetails.Visibility = ViewStates.Visible;
                 }
 
-			if ( (!_showGroupFullPath) || (!_isSearchResult) ) {
+                if ((!_showGroupFullPath) || (!_isSearchResult))
+                {
                     _textgroupFullPath.Visibility = ViewStates.Gone;
                 }
 
-			else {
+                else
+                {
                     String groupDetail = pw.ParentGroup.GetFullPath();
                     if (App.Kp2a.OpenDatabases.Count() > 1)
                     {
@@ -197,7 +203,8 @@ namespace keepass2android.view
 
                     var strGroupDetail = new SpannableString(groupDetail);
 
-				if (isExpired) {
+                    if (isExpired)
+                    {
                         strGroupDetail.SetSpan(new StrikethroughSpan(), 0, groupDetail.Length, SpanTypes.ExclusiveExclusive);
                     }
                     _textgroupFullPath.TextFormatted = strGroupDetail;
@@ -208,10 +215,12 @@ namespace keepass2android.view
                 //try to get totp data
                 UpdateTotp();
 
+            }
+            catch (Exception e)
+            {
+                Kp2aLog.LogUnexpectedError(e);
 
-           
+            }
-                
-
 
 
         }