Execution time and place as DEBUG indicators

open-reac/src/main/resources/openreac/reactiveopfoutput.run

@@ -229,26 +229,26 @@ let fileOut := "reactiveopf_results_indic.txt";
 printf "%s %s\n","final_status",final_status > (fileOut);
 printf "%s %s\n","dcopf_status",dcopf_status > (fileOut);
 
-printf "\n" > (fileOut);
-printf "%s %Q\n","ctime_start",ctime_start > (fileOut);
-printf "%s %i\n","last_solve_result_num",solve_result_num > (fileOut);
-printf "%s %i\n","nb_iter_last",nb_iter_last > (fileOut);
-printf "%s %i\n","nb_iter_total",nb_iter_total > (fileOut);
-printf "%s %f\n","_ampl_elapsed_time",_ampl_elapsed_time > (fileOut);
-printf "%s %f\n","_total_solve_time",_total_solve_time > (fileOut);
-printf "%s %i\n","total_time",_total_solve_time+_ampl_elapsed_time > (fileOut);
-
-printf "\n" > (fileOut);
-printf "%s %s\n","operatingSystem",operatingSystem > (fileOut);
+printf{LOG_DEBUG} "\n" > (fileOut);
+printf{LOG_DEBUG} "%s %Q\n","ctime_start",ctime_start > (fileOut);
+printf{LOG_DEBUG} "%s %i\n","last_solve_result_num",solve_result_num > (fileOut);
+printf{LOG_DEBUG} "%s %i\n","nb_iter_last",nb_iter_last > (fileOut);
+printf{LOG_DEBUG} "%s %i\n","nb_iter_total",nb_iter_total > (fileOut);
+printf{LOG_DEBUG} "%s %f\n","_ampl_elapsed_time",_ampl_elapsed_time > (fileOut);
+printf{LOG_DEBUG} "%s %f\n","_total_solve_time",_total_solve_time > (fileOut);
+printf{LOG_DEBUG} "%s %i\n","total_time",_total_solve_time+_ampl_elapsed_time > (fileOut);
+
+printf{LOG_DEBUG} "\n" > (fileOut);
+printf{LOG_DEBUG} "%s %s\n","operatingSystem",operatingSystem > (fileOut);
 if length($OS) > 0 then {
-  printf "%s %Q\n","OS",$OS > (fileOut); # Windows
-  printf "%s %Q\n","COMPUTERNAME",$COMPUTERNAME > (fileOut);
+  printf{LOG_DEBUG} "%s %Q\n","OS",$OS > (fileOut); # Windows
+  printf{LOG_DEBUG} "%s %Q\n","COMPUTERNAME",$COMPUTERNAME > (fileOut);
 }
 if length($SHELL) > 0 then {
-  printf "%s %Q\n","SHELL",$SHELL > (fileOut); # Linux
-  printf "%s %Q\n","HOSTNAME",$HOSTNAME > (fileOut);
+  printf{LOG_DEBUG} "%s %Q\n","SHELL",$SHELL > (fileOut); # Linux
+  printf{LOG_DEBUG} "%s %Q\n","HOSTNAME",$HOSTNAME > (fileOut);
 }
-printf "%s %Q\n","directory",_cd > (fileOut);
+printf{LOG_DEBUG} "%s %Q\n","directory",_cd > (fileOut);
 
 printf "\n" > (fileOut);
 printf "%s %s\n","log_level_ampl",log_level_ampl > (fileOut);

open-reac/src/test/java/com/powsybl/openreac/optimization/OpenReacAmplIOTest.java

@@ -15,6 +15,7 @@
 import com.powsybl.openreac.OpenReacConfig;
 import com.powsybl.openreac.OpenReacRunner;
 import com.powsybl.openreac.parameters.input.OpenReacParameters;
+import com.powsybl.openreac.parameters.input.algo.OpenReacAmplLogLevel;
 import com.powsybl.openreac.parameters.input.algo.OpenReacOptimisationObjective;
 import com.powsybl.openreac.parameters.input.algo.ReactiveSlackBusesMode;
 import com.powsybl.openreac.parameters.output.OpenReacResult;
@@ -27,8 +28,7 @@
 import java.util.concurrent.ForkJoinPool;
 import java.util.stream.Collectors;
 
-import static org.junit.jupiter.api.Assertions.assertEquals;
-import static org.junit.jupiter.api.Assertions.assertTrue;
+import static org.junit.jupiter.api.Assertions.*;
 
 /**
  * @author Geoffroy Jamgotchian {@literal <geoffroy.jamgotchian at rte-france.com>}
@@ -133,9 +133,36 @@ void testOutputFileParsing() throws IOException {
             assertEquals(1, openReacResult.getVscModifications().size());
             assertEquals(7, openReacResult.getGeneratorModifications().size());
             assertEquals(3, openReacResult.getVoltageProfile().size());
-            assertEquals(87, openReacResult.getIndicators().size());
+            assertEquals(76, openReacResult.getIndicators().size());
             assertTrue(openReacResult.getReactiveSlacks().isEmpty());
         }
     }
 
+    @Test
+    void testDebugIndicators() throws IOException {
+        Network network = IeeeCdfNetworkFactory.create14();
+        setDefaultVoltageLimits(network);
+        LocalCommandExecutor localCommandExecutor = new TestLocalCommandExecutor(List.of("optimization/indicators/debug-log-level-indicators/reactiveopf_results_indic.txt"));
+        try (ComputationManager computationManager = new LocalComputationManager(new LocalComputationConfig(tmpDir),
+                localCommandExecutor, ForkJoinPool.commonPool())) {
+            OpenReacParameters parameters = new OpenReacParameters();
+            parameters.setLogLevelAmpl(OpenReacAmplLogLevel.DEBUG);
+            OpenReacResult openReacResult = OpenReacRunner.run(network,
+                    network.getVariantManager().getWorkingVariantId(), parameters, new OpenReacConfig(true),
+                    computationManager);
+            assertEquals(87, openReacResult.getIndicators().size());
+            assertEquals("Tue Dec 17 18:49:34 2024", openReacResult.getIndicators().get("ctime_start"));
+            assertEquals(0, Integer.parseInt(openReacResult.getIndicators().get("last_solve_result_num")));
+            assertEquals(5, Integer.parseInt(openReacResult.getIndicators().get("nb_iter_last")));
+            assertEquals(5, Integer.parseInt(openReacResult.getIndicators().get("nb_iter_total")));
+            assertEquals(0.095, Double.parseDouble(openReacResult.getIndicators().get("_ampl_elapsed_time")));
+            assertEquals(0.0625, Double.parseDouble(openReacResult.getIndicators().get("_total_solve_time")));
+            assertEquals(0, Double.parseDouble(openReacResult.getIndicators().get("total_time")));
+            assertEquals("windows", openReacResult.getIndicators().get("operatingSystem"));
+            assertEquals("Windows_NT", openReacResult.getIndicators().get("OS"));
+            assertEquals("A-COMPUTER-NAME", openReacResult.getIndicators().get("COMPUTERNAME"));
+            assertEquals("C:\\Users\\user\\AppData\\Local\\Temp\\ampl_tmp", openReacResult.getIndicators().get("directory"));
+        }
+    }
+
 }

open-reac/src/test/resources/mock_outputs/reactiveopf_results_indic.txt

@@ -1,19 +1,6 @@
 final_status OK
 dcopf_status OK
 
-ctime_start 'Mon Apr 01 12:23:50 2024'
-last_solve_result_num 0
-nb_iter_last 6
-nb_iter_total 6
-_ampl_elapsed_time 0.078000
-_total_solve_time 0.046875
-total_time 0
-
-operatingSystem windows
-OS 'Windows_NT'
-COMPUTERNAME 'ARTELYS-PC253'
-directory 'C:\Users\parvy\AppData\Local\Temp\ampl_13599896811417343310'
-
 log_level_ampl INFO
 log_level_knitro 2
 objective_choice 0

open-reac/src/test/resources/optimization/indicators/debug-log-level-indicators/reactiveopf_results_indic.txt

@@ -0,0 +1,93 @@
+final_status OK
+dcopf_status OK
+
+ctime_start 'Tue Dec 17 18:49:34 2024'
+last_solve_result_num 0
+nb_iter_last 5
+nb_iter_total 5
+_ampl_elapsed_time 0.095000
+_total_solve_time 0.062500
+total_time 0
+
+operatingSystem windows
+OS 'Windows_NT'
+COMPUTERNAME 'A-COMPUTER-NAME'
+directory 'C:\Users\user\AppData\Local\Temp\ampl_tmp'
+
+log_level_ampl DEBUG
+log_level_knitro 2
+objective_choice 0
+ratio_voltage_target 0.500000
+coeff_alpha 1.000000
+Pnull 0.010000
+Znull 0.000100
+epsilon_nominal_voltage 1.000000
+min_plausible_low_voltage_limit 0.500000
+max_plausible_high_voltage_limit 1.500000
+ignore_voltage_bounds 0.000000
+buses_with_reactive_slacks ALL
+PQmax 9000.000000
+defaultPmax 1000.000000
+defaultPmin 0.000000
+defaultQmaxPmaxRatio 0.300000
+defaultQmin -300.000000
+defaultQmax 300.000000
+minimalQPrange 1.000000
+default_variable_scaling_factor 1.000000
+default_constraint_scaling_factor 1.000000
+reactive_slack_variable_scaling_factor 0.100000
+transformer_ratio_variable_scaling_factor 0.001000
+shunt_variable_scaling_factor 0.100000
+
+nb_substations 14
+nb_bus_in_data_file 14
+nb_bus_in_ACDC_CC 14
+nb_bus_in_AC_CC 14
+nb_bus_in_ACDC_but_out_AC_CC 0
+nb_bus_with_voltage_value 14
+nb_bus_with_reactive_slacks 14
+nb_bus_without_reactive_slacks 0
+nb_branch_in_data_file 20
+nb_branch_in_AC_CC 20
+nb_branch_with_nonsmall_impedance 20
+nb_branch_with_zero_or_small_impedance 0
+nb_unit_in_data_file 5
+nb_unit_in_AC_CC 5
+nb_unit_up_and_running 2
+nb_unit_with_variable_reactive_power 2
+nb_unit_with_fixed_reactive_power 0
+nb_load_in_data_file 11
+nb_load_in_AC_CC 11
+nb_shunt_in_data_file 1
+nb_shunt_connectable_or_in_AC_CC 1
+nb_shunt_with_fixed_value 1
+nb_shunt_with_variable_value 0
+nb_transformers_with_variable_ratio 0
+nb_transformers_with_fixed_ratio 0
+nb_svc_in_data_file 0
+nb_svc_in_AC_CC 0
+nb_svc_up_and_operating 0
+nb_vsc_converter_in_data_file 0
+nb_vsc_converter_up_and_running 0
+nb_lcc_converter_in_data_file 0
+nb_lcc_converter_up_and_running 0
+nb_batteries 0
+sum_batteries_pmax 0.0
+sum_batteries_pmin 0.0
+
+max_teta_dc 0.19
+max_teta_ac 0.09
+teta_max 3.19
+min_teta_dc -0.12
+min_teta_ac -0.05
+teta_min -3.12
+max_delta_teta_dc 0.159381
+max_delta_teta_ac 0.076647
+min_delta_teta_dc -0.041401
+min_delta_teta_ac -0.018540
+
+nb_reactive_slacks 0
+nb_slacks_condensator 0
+sum_slacks_condensator 0.0
+nb_slacks_self 0
+sum_slacks_self 0.0

open-reac/src/test/resources/optimization/loadflow/openreac-output-ieee14/reactiveopf_results_indic.txt

@@ -1,19 +1,6 @@
 final_status OK
 dcopf_status OK
 
-ctime_start 'Thu Jun 20 14:34:11 2024'
-last_solve_result_num 0
-nb_iter_last 6
-nb_iter_total 6
-_ampl_elapsed_time 0.032000
-_total_solve_time 0.000000
-total_time 0
-
-operatingSystem windows
-OS 'Windows_NT'
-COMPUTERNAME 'ARTELYS-PC253'
-directory 'C:\Users\parvy\AppData\Local\Temp\ampl_15080248147598462242'
-
 log_level_ampl INFO
 log_level_knitro 2
 objective_choice 0

open-reac/src/test/resources/optimization/loadflow/openreac-output-real-network/reactiveopf_results_indic.txt

@@ -1,19 +1,6 @@
 final_status OK
 dcopf_status OK
 
-ctime_start 'Thu Jun 20 14:42:54 2024'
-last_solve_result_num 0
-nb_iter_last 7
-nb_iter_total 7
-_ampl_elapsed_time 0.078000
-_total_solve_time 0.031250
-total_time 0
-
-operatingSystem windows
-OS 'Windows_NT'
-COMPUTERNAME 'ARTELYS-PC253'
-directory 'C:\Users\parvy\AppData\Local\Temp\ampl_16419245349654459503'
-
 log_level_ampl INFO
 log_level_knitro 2
 objective_choice 0

open-reac/src/test/resources/optimization/loadflow/openreac-output-shunt/reactiveopf_results_indic.txt

@@ -1,19 +1,6 @@
 final_status OK
 dcopf_status OK
 
-ctime_start 'Thu Jun 20 14:41:11 2024'
-last_solve_result_num 0
-nb_iter_last 35
-nb_iter_total 35
-_ampl_elapsed_time 0.047000
-_total_solve_time 0.031250
-total_time 0
-
-operatingSystem windows
-OS 'Windows_NT'
-COMPUTERNAME 'ARTELYS-PC253'
-directory 'C:\Users\parvy\AppData\Local\Temp\ampl_10955859460968685093'
-
 log_level_ampl INFO
 log_level_knitro 2
 objective_choice 0

open-reac/src/test/resources/optimization/loadflow/openreac-output-svc/reactiveopf_results_indic.txt

@@ -1,19 +1,6 @@
 final_status OK
 dcopf_status OK
 
-ctime_start 'Thu Jun 20 14:40:34 2024'
-last_solve_result_num 0
-nb_iter_last 6
-nb_iter_total 6
-_ampl_elapsed_time 0.047000
-_total_solve_time 0.015625
-total_time 0
-
-operatingSystem windows
-OS 'Windows_NT'
-COMPUTERNAME 'ARTELYS-PC253'
-directory 'C:\Users\parvy\AppData\Local\Temp\ampl_11839740265781623806'
-
 log_level_ampl INFO
 log_level_knitro 2
 objective_choice 0

open-reac/src/test/resources/optimization/loadflow/openreac-output-vsc/reactiveopf_results_indic.txt

@@ -1,19 +1,6 @@
 final_status OK
 dcopf_status OK
 
-ctime_start 'Thu Jun 20 14:38:57 2024'
-last_solve_result_num 0
-nb_iter_last 6
-nb_iter_total 6
-_ampl_elapsed_time 0.047000
-_total_solve_time 0.031250
-total_time 0
-
-operatingSystem windows
-OS 'Windows_NT'
-COMPUTERNAME 'ARTELYS-PC253'
-directory 'C:\Users\parvy\AppData\Local\Temp\ampl_4294773797099927510'
-
 log_level_ampl INFO
 log_level_knitro 2
 objective_choice 0