debug timing added for performance test

src/damaris/gui/DamarisGUI.py

@@ -501,6 +501,9 @@ class DamarisGUI:
         dialog.destroy()
 
     def start_experiment( self, widget, data=None ):
+        import time
+        overall_start = time.time()
+        print(f"DEBUG: start_experiment called at {overall_start}")
 
         # something running?
         if self.si is not None:
@@ -508,11 +511,15 @@ class DamarisGUI:
         self.si = None
 
         # get config values:
+        config_start = time.time()
         actual_config = self.config.get( )
+        print(f"DEBUG: Config load took {time.time() - config_start:.3f}s")
 
         # get scripts and start script interface
+        gui_start = time.time()
         self.sw.disable_editing( )
         exp_script, res_script = self.sw.get_scripts( )
+        print(f"DEBUG: GUI operations took {time.time() - gui_start:.3f}s")
         if not actual_config[ "start_result_script" ]:
             res_script = ""
         if not actual_config[ "start_experiment_script" ]:
@@ -528,6 +535,7 @@ class DamarisGUI:
 
         # check whether scripts are syntactically valid
         # should be merged with check script function
+        compile_start = time.time()
         exp_code = None
         if exp_script != "":
             try:
@@ -547,6 +555,7 @@ class DamarisGUI:
 
         res_code = None
         if res_script != "":
+            # Continue with result script compilation
             try:
                 res_code = compile( res_script, "Result Script", "exec" )
             except SyntaxError as e:
@@ -563,6 +572,8 @@ class DamarisGUI:
                     pass
                 print(e)
 
+        print(f"DEBUG: Script compilation took {time.time() - compile_start:.3f}s")
+
         # detect error
         if (exp_script != "" and exp_code is None) or \
                 (res_script != "" and res_code is None):
@@ -590,7 +601,16 @@ class DamarisGUI:
         interval = 0.1
         self.stop_experiment_flag.clear()
 
+        # Add timing debug info
+        import time
+        start_time = time.time()
+        print(f"DEBUG: Starting experiment at {start_time}")
+
         self.id = self.lockfile.add_experiment()
+        print(f"DEBUG: Lock file operation took {time.time() - start_time:.3f}s")
+        
+        # Add more timing points
+        lock_wait_start = time.time()
         while not self.lockfile.am_i_next():
             while gtk.events_pending():
                 gtk.main_iteration_do(False)
@@ -601,7 +621,9 @@ class DamarisGUI:
                 loop_run = 0
             loop_run += interval
 
-            if self.stop_experiment_flag.isSet():
+        print(f"DEBUG: Lock wait took {time.time() - lock_wait_start:.3f}s")
+
+        if self.stop_experiment_flag.isSet():
                 #Experiment has been stopped, clean up and leave
                 self.experiment_script_statusbar_label.set_text("Experiment stopped")
                 self.state = DamarisGUI.Edit_State
@@ -618,19 +640,26 @@ class DamarisGUI:
         try:
             self.spool_dir = os.path.abspath( actual_config[ "spool_dir" ] )
             # setup script engines
+            script_interface_start = time.time()
             self.si = ScriptInterface( exp_code,
                                        res_code,
                                        backend,
                                        self.spool_dir,
                                        clear_jobs=actual_config[ "del_jobs_after_execution" ],
                                        clear_results=actual_config[ "del_results_after_processing" ] )
+            print(f"DEBUG: ScriptInterface creation took {time.time() - script_interface_start:.3f}s")
 
             self.data = self.si.data
             # run frontend and script engines
             self.monitor.observe_data_pool( self.data )
             # Start temperature monitoring if configured (before scripts start)
+            temp_start = time.time()
             self.start_temperature_monitoring(actual_config)
+            print(f"DEBUG: Temperature monitoring startup took {time.time() - temp_start:.3f}s")
+            
+            scripts_start = time.time()
             self.si.runScripts( )
+            print(f"DEBUG: Script execution startup took {time.time() - scripts_start:.3f}s")
         except Exception as e:
             #print "ToDo evaluate exception",str(e), "at",traceback.extract_tb(sys.exc_info()[2])[-1][1:3]
             #print "Full traceback:"
@@ -807,6 +836,11 @@ class DamarisGUI:
             self.stop_temperature_monitoring()
             if self.save_thread is None and self.dump_filename != "":
                 print("all subprocesses ended, saving data pool")
+                # Disable run button during data saving to prevent UI confusion
+                gdk.threads_enter()
+                self.toolbar_run_button.set_sensitive(False)
+                gdk.threads_leave()
+                
                 # thread to save data...
                 self.save_thread = threading.Thread( target=self.dump_states, name="dump states" )
                 self.save_thread.start( )
@@ -1012,7 +1046,13 @@ class DamarisGUI:
         # save the data!
         self.data.write_hdf5( dump_file, where="/", name="data_pool",
                               complib=self.dump_complib, complevel=self.dump_complevel,
-                              incremental=not init )
+                              incremental=not init, write_interval=self.dump_timeinterval )
+
+        # Re-enable run button if this was called from save thread
+        if not init and threading.current_thread().name == "dump states":
+            gdk.threads_enter()
+            self.toolbar_run_button.set_sensitive(True)
+            gdk.threads_leave()
 
         # now save additional information
         e = self.si.data.get( "__recentexperiment", -1 ) + 1