| 1 | | % (c) 2014-2025 Lehrstuhl fuer Softwaretechnik und Programmiersprachen, |
| 2 | | % Heinrich Heine Universitaet Duesseldorf |
| 3 | | % This software is licenced under EPL 1.0 (http://www.eclipse.org/org/documents/epl-v10.html) |
| 4 | | |
| 5 | | :- module(runtime_profiler,[reset_runtime_profiler/0, |
| 6 | | profile_failure_driven_loop/1, profile_failure_driven_loop/2, |
| 7 | | profile_single_call/2, profile_single_call/3, profile_single_call/4, |
| 8 | | register_profiler_runtime/5, % manually register runtimes |
| 9 | | tcltk_get_profile_info/1, tcltk_get_profile_info/2, |
| 10 | | tcltk_get_operations_profile_info/1, tcltk_get_constants_profile_info/1, |
| 11 | | tcltk_dot_constants_profile_info/1, |
| 12 | | runtime_profile_available/0, |
| 13 | | print_runtime_profile/0, % called e.g. by -prob_profile |
| 14 | | |
| 15 | | start_profile/2, opt_stop_profile/5, |
| 16 | | stop_constant_profile/5, |
| 17 | | constants_profiling_on/0, |
| 18 | | |
| 19 | | runtime_observe_available/0, |
| 20 | | observe_runtime_wf/4, |
| 21 | | |
| 22 | | profile_recursion/3 |
| 23 | | ]). |
| 24 | | |
| 25 | | % TO DO: optionally load more precise microsecond timer |
| 26 | | |
| 27 | | :- use_module(module_information,[module_info/2]). |
| 28 | | :- module_info(group,profiling). |
| 29 | | :- module_info(description,'This module provides a simple runtime profiler.'). |
| 30 | | |
| 31 | | :- load_files(library(system), [when(compile_time), imports([environ/2])]). |
| 32 | | |
| 33 | | |
| 34 | | :- use_module(probsrc(kernel_waitflags),[add_message_wf/5, get_waitflags_phase/2, get_call_stack/2]). |
| 35 | | :- use_module(preferences,[preference/2,get_preference/2]). |
| 36 | | :- use_module(probsrc(tools_strings),[ajoin/2]). |
| 37 | | runtime_observe_available :- preference(performance_monitoring_on,true). |
| 38 | | |
| 39 | | observe_runtime_wf(Timer,Msg,Span,WF) :- |
| 40 | | preference(performance_monitoring_on,true), |
| 41 | | Timer = [Start,WStart], |
| 42 | | !, |
| 43 | | get_preference(performance_monitoring_expansion_limit,Limit), |
| 44 | | statistics(runtime,[End,_]), TotRuntime is End-Start, |
| 45 | | statistics(walltime,[WEnd,_]), TotWalltime is WEnd-WStart, |
| 46 | | (TotWalltime>=Limit |
| 47 | | -> ajoin([TotWalltime,' ms'],Time), |
| 48 | | add_message_wf(delay,Msg,Time,Span,WF), |
| 49 | | (get_call_stack(WF,Stack), |
| 50 | | member(id_equality_evaluation(ID,constant,_Pos),Stack), |
| 51 | | write(id(ID)),nl, |
| 52 | | get_waitflags_phase(WF,Phase), |
| 53 | | Cat = constant_computation(Phase,[long_closure_expansion]), |
| 54 | | register_profiler_runtime(ID,Cat,unknown,TotRuntime,TotWalltime), |
| 55 | | fail ; true) |
| 56 | | ; true). |
| 57 | | observe_runtime_wf(_StartMs,_Msg,_,_). |
| 58 | | |
| 59 | | :- dynamic recursion_level/1. |
| 60 | | % TO DO: use counter |
| 61 | | recursion_level(0). |
| 62 | | inc_recur(X) :- retract(recursion_level(X)), X1 is X+1, |
| 63 | | assertz(recursion_level(X1)). |
| 64 | | dec_recur(X) :- retract(recursion_level(X1)), X is X1-1, |
| 65 | | assertz(recursion_level(X)). |
| 66 | | reset_recur(X) :- retract(recursion_level(_)), assertz(recursion_level(X)). |
| 67 | | :- meta_predicate profile_recursion(0,+,+). |
| 68 | | profile_recursion(Call,Name,Arg) :- |
| 69 | | inc_recur(X), |
| 70 | | statistics(walltime,[Start,_]), |
| 71 | | indent(X),format('>> ~w,~w,~w ms (ENTER),~w~n',[X1,Name,Start,Arg]), |
| 72 | | call_cleanup(Call, |
| 73 | | (statistics(walltime,[End,_]), Tot is End-Start, |
| 74 | | indent(X),format('<< ~w,~w,~w ms (EXIT)~n',[X1,Name,Tot]), |
| 75 | | reset_recur(X) |
| 76 | | )). |
| 77 | | indent(0) :- !. |
| 78 | | indent(N) :- N>0,!, N1 is N-1, print(' '), indent(N1). |
| 79 | | |
| 80 | | |
| 81 | | tcltk_get_profile_info(List) :- tcltk_get_profile_info(_,List). |
| 82 | | % can be generated from command-line using -csv prob_profile_info FILE |
| 83 | | tcltk_get_operations_profile_info(List) :- |
| 84 | | tcltk_get_profile_info(top_level,List). |
| 85 | | |
| 86 | | |
| 87 | | :- if(environ(prob_profile, false)). %used to be \+ environ(prob_profile, true)). |
| 88 | | % completely disable profiling |
| 89 | | reset_runtime_profiler. |
| 90 | | :- meta_predicate profile_single_call(-,-,-,0). |
| 91 | | profile_single_call(_Label,_Cat,_ID,C) :- call(C). |
| 92 | | :- meta_predicate profile_single_call(-,-,0). |
| 93 | | profile_single_call(_Label,_ID,C) :- call(C). |
| 94 | | :- meta_predicate profile_single_call(-,0). |
| 95 | | profile_single_call(_Label,C) :- call(C). |
| 96 | | register_profiler_runtime(_,_,_,_,_). |
| 97 | | profile_failure_driven_loop(_). |
| 98 | | profile_failure_driven_loop(_,_). |
| 99 | | print_runtime_profile :- |
| 100 | | print('No runtime profiling information available'),nl, |
| 101 | | print('Recompile ProB with -Dprob_profile=true'),nl. |
| 102 | | tcltk_get_profile_info(_,list([I1,I2])) :- |
| 103 | | I1='No runtime profiling information available', |
| 104 | | I2='Recompile ProB with -Dprob_profile=true'. |
| 105 | | tcltk_get_constants_profile_info(List) :- tcltk_get_profile_info(_,List). |
| 106 | | runtime_profile_available :- fail. |
| 107 | | |
| 108 | | start_profile(_,_). |
| 109 | | stop_profile(_,_,_). |
| 110 | | opt_stop_profile(_,_,_,_,_). |
| 111 | | stop_constant_profile(_,_,_,_,_). |
| 112 | | constants_profiling_on :- fail. |
| 113 | | |
| 114 | | :- else. |
| 115 | | runtime_profile_available :- preference(prob_profiling_on,true). |
| 116 | | |
| 117 | | :- volatile total_runtime/8. |
| 118 | | :- dynamic total_runtime/8. |
| 119 | | |
| 120 | | reset_runtime_profiler :- % print('RESET '),nl, print_runtime_profile, |
| 121 | | retractall(total_runtime(_,_,_,_,_,_,_,_)). |
| 122 | | |
| 123 | | :- use_module(eventhandling,[register_event_listener/3]). |
| 124 | | :- register_event_listener(clear_specification,reset_runtime_profiler, |
| 125 | | 'Reset runtime profiler.'). |
| 126 | | |
| 127 | | :- meta_predicate profile_single_call(-,-,-,0). |
| 128 | ? | profile_single_call(_,_,_,Call) :- preference(prob_profiling_on,false), !, call(Call). |
| 129 | | profile_single_call(Label,Category,StateID,C) :- |
| 130 | | start_profile(Label,StartInfo), |
| 131 | | if(call(C), |
| 132 | | stop_profile(Label,Category,StateID,StartInfo), |
| 133 | | (stop_profile(Label,Category,StateID,StartInfo),fail)). |
| 134 | | |
| 135 | | :- meta_predicate profile_single_call(-,-,0). |
| 136 | ? | profile_single_call(Label,StateID,C) :- profile_single_call(Label,top_level,StateID,C). |
| 137 | | |
| 138 | | :- meta_predicate profile_single_call(-,0). |
| 139 | | profile_single_call(Label,C) :- profile_single_call(Label,top_level,unknown,C). |
| 140 | | |
| 141 | | |
| 142 | | % register runtime for a failure driven loop: |
| 143 | | profile_failure_driven_loop(ActionName) :- profile_failure_driven_loop(ActionName,unknown). |
| 144 | | |
| 145 | | profile_failure_driven_loop(_,_) :- preference(prob_profiling_on,false), !. |
| 146 | | profile_failure_driven_loop(ActionName,StateID) :- |
| 147 | | start_profile(ActionName,Info), |
| 148 | | %format('Start Action ----> ~w (~w)~n',[ActionName,Info]), |
| 149 | | register_time(ActionName,StateID,Info). |
| 150 | | register_time(_,_,_). |
| 151 | | register_time(AN,StateID,Info) :- |
| 152 | | stop_profile(AN,StateID,Info), |
| 153 | | fail. |
| 154 | | |
| 155 | | start_profile(_,P) :- preference(prob_profiling_on,false), !, P=[0,0]. |
| 156 | | start_profile(_Label,[RT1,WT1]) :- |
| 157 | | statistics(runtime,[RT1,_Delta]), |
| 158 | | statistics(walltime,[WT1,_]). |
| 159 | | % inc_recur(X), indent(X), format('>> ~w, ~w, ~w ms (ENTER)~n',[X,_Label,WT1]). |
| 160 | | |
| 161 | | stop_profile(Label,StateID,StartTimes) :- |
| 162 | | stop_profile(Label,top_level,StateID,StartTimes). |
| 163 | | |
| 164 | | stop_profile(_,_,_,_) :- preference(prob_profiling_on,false), !. |
| 165 | | stop_profile(Label,Category,StateID,[RT1,WT1]) :- |
| 166 | | statistics(runtime,[RT2,_]), |
| 167 | | statistics(walltime,[WT2,_]), |
| 168 | | DRT is RT2-RT1, DWT is WT2-WT1, |
| 169 | | %dec_recur(X),indent(X), format('<< ~w, ~w, ~w ms (EXIT)~n',[X,Label,DWT]), |
| 170 | | %format('Runtime for ~w : ~w ms (~w wall)~n',[AN,DRT,DWT]), |
| 171 | | register_profiler_runtime(Label,Category,StateID,DRT,DWT). |
| 172 | | % now a version with an additional prefix context and only register values with a certain threshold |
| 173 | | opt_stop_profile(_,_,_,_,_) :- preference(prob_profiling_on,false), !. |
| 174 | | opt_stop_profile(Category,Label,StateID,[RT1,WT1],Threshold) :- |
| 175 | | statistics(walltime,[WT2,_]), DWT is WT2-WT1, DWT>=Threshold, |
| 176 | | !, |
| 177 | | statistics(runtime,[RT2,_]), |
| 178 | | DRT is RT2-RT1, |
| 179 | | register_profiler_runtime(Label,Category,StateID,DRT,DWT). |
| 180 | | opt_stop_profile(_,_,_,_,_). |
| 181 | | |
| 182 | | % register_profiler_runtime(Label,Category,StateID,DeltaRunTime,DeltaWallTime) |
| 183 | | register_profiler_runtime(_,_,_,_,_) :- preference(prob_profiling_on,false), !. |
| 184 | | %register_profiler_runtime(_,_,_,0,0) :- !. % comment out if you want to count all calls |
| 185 | | register_profiler_runtime(ProgramPoint,Category,StateID,RTime,WTime) :- |
| 186 | | (var(ProgramPoint) -> PP2='unknown' ; PP2 = ProgramPoint), |
| 187 | | (retract(total_runtime(PP2,Category,OldR,OldW,Calls,Max,MaxID,Min)) |
| 188 | | -> true |
| 189 | | ; OldR=0,OldW=0,Max=0,MaxID=StateID,Calls=0,Min=inf |
| 190 | | ), |
| 191 | | ((RTime<0 ; WTime <0) -> print(negative_runtime(PP2,StateID,RTime,WTime)),nl ; true), |
| 192 | | NewR is OldR+RTime, NewW is OldW+WTime, NewCalls is Calls+1, |
| 193 | | (WTime > Max -> NewMax = WTime, NewMaxID=StateID ; NewMax = Max, NewMaxID=MaxID), |
| 194 | | (number(Min), Min < WTime -> NewMin = Min ; NewMin = WTime), |
| 195 | | assertz(total_runtime(PP2,Category,NewR,NewW,NewCalls,NewMax,NewMaxID,NewMin)). |
| 196 | | |
| 197 | | |
| 198 | | |
| 199 | | constants_profiling_on :- preference(performance_monitoring_on,true). % TODO: maybe use other preference later |
| 200 | | |
| 201 | | stop_constant_profile(Val,Phase,ID,IDInfo,Timer) :- |
| 202 | | (get_value_info(Val,ValKind) -> IDInfo2 = [ValKind|IDInfo] ; IDInfo2=IDInfo), |
| 203 | | opt_stop_profile(constant_computation(Phase,IDInfo2),ID,root,Timer,0). |
| 204 | | |
| 205 | | get_value_info(Var,ValKind) :- var(Var),!, ValKind=variable. |
| 206 | | get_value_info(closure(_,_,_),ValKind) :- !, ValKind=symbolic. |
| 207 | | get_value_info(avl_set(_),ValKind) :- !, ValKind=avl_set. |
| 208 | | get_value_info(rec(_),ValKind) :- !, ValKind=record. |
| 209 | | get_value_info(int(_),ValKind) :- !, ValKind=integer. |
| 210 | | get_value_info(string(_),ValKind) :- !, ValKind=string. |
| 211 | | get_value_info(fd(_,GS),ValKind) :- !, ValKind=GS. |
| 212 | | get_value_info(freeval(_ID,_,_),ValKind) :- !, ValKind=freeval. |
| 213 | | get_value_info(pred_false,ValKind) :- !, ValKind=boolean. |
| 214 | | get_value_info(pred_true,ValKind) :- !, ValKind=boolean. |
| 215 | | get_value_info([],ValKind) :- !, ValKind=empty_set. |
| 216 | | get_value_info(O,other) :- functor(O,F,N), write(other(F,N)),nl,fail. |
| 217 | | |
| 218 | | % remove this from the info field, when we have a description about the constant value found (get_det_solution_for_constant_value_kind) |
| 219 | | is_value_info(avl_set). |
| 220 | | is_value_info(boolean). |
| 221 | | is_value_info(empty_set). |
| 222 | | is_value_info(freeval). |
| 223 | | is_value_info(integer). |
| 224 | | is_value_info(record). |
| 225 | | is_value_info(symbolic). |
| 226 | | is_value_info(string). |
| 227 | | |
| 228 | | |
| 229 | | translate_pp(PP,Cat,PPS) :- member(Cat,[top_level,external_functions,well_def_analyser]),!, |
| 230 | | translate_term_into_atom(PP,PPS). |
| 231 | | translate_pp(PP,constant_computation(Phase,IDInfo),PPS) :- !, |
| 232 | | ajoin([PP,'::',Phase,'::',IDInfo],PPS). % TODO: improve rendering of IDInfo |
| 233 | | translate_pp(PP,Category,PPS) :- ajoin([PP,'::',Category],PPS). |
| 234 | | |
| 235 | | |
| 236 | | relevant_total_runtime(PP,Cat,RT,WT,Calls,MaxWT,MaxID,Min) :- |
| 237 | | total_runtime(PP,Cat,RT,WT,Calls,MaxWT,MaxID,Min), |
| 238 | | \+ irrelevant_profile_entry(PP,Cat,WT). |
| 239 | | |
| 240 | | irrelevant_profile_entry(ID,constant_computation(Phase,IDInfo),0) :- |
| 241 | | Phase = propagate_value, % only show propagations if relevant runtime or instantiates something other than itself |
| 242 | | (member(instantiates(List),IDInfo) -> List = [ID] ; true). |
| 243 | | |
| 244 | | :- use_module(library(lists)). |
| 245 | | print_runtime_profile :- |
| 246 | | format('---- ProB Runtime Profiler ----~n',[]), |
| 247 | | format('---- Time spent in B operations and invariant evaluation~n',[]), |
| 248 | | (get_preference(prob_profiling_on,false) -> |
| 249 | | format('---- *** set preference PROFILING_INFO to TRUE to obtain more information!~n',[]) ; true), |
| 250 | | print_runtime_profile(top_level), |
| 251 | | |
| 252 | | format('---- Time spent evaluating CONSTANTS (defined by equations)~n',[]), |
| 253 | | print_runtime_profile(constant_computation(_,_)), |
| 254 | | |
| 255 | ? | (opt_category(Category), |
| 256 | | \+ \+ total_runtime(_,Category,_,_,_,_,_,_), |
| 257 | | format('---- Time spent evaluating ~w~n',[Category]), |
| 258 | | print_runtime_profile(Category), |
| 259 | | fail |
| 260 | | ; |
| 261 | | true). |
| 262 | | |
| 263 | | opt_category(ast_cleanup). |
| 264 | | opt_category(external_functions). |
| 265 | | opt_category(well_def_analyser). |
| 266 | | |
| 267 | | :- use_module(specfile,[get_specification_description/2]). |
| 268 | | get_category_call_name(top_level,N) :- !, |
| 269 | | get_specification_description(operation,N). % also shows invariants though |
| 270 | | get_category_call_name(external_functions,N) :- !, N='Function'. |
| 271 | | get_category_call_name(_,N) :- !, N='Call'. |
| 272 | | |
| 273 | | |
| 274 | | print_runtime_profile(Cat) :- |
| 275 | | get_category_call_name(Cat,Col1Header), |
| 276 | | format(' ~w : ~w ms (~w ms walltime & ~w - ~w ms walltime; #calls ~w)~n', |
| 277 | | [Col1Header,'Total Runtime','Total','Minimum','Maximum','Number of Calls']), |
| 278 | | findall(profile(RT,WT,Calls,MaxWT,PP,Cat,MaxID,Min),relevant_total_runtime(PP,Cat,RT,WT,Calls,MaxWT,MaxID,Min),List), |
| 279 | | sort(List,SL), |
| 280 | | reverse(SL,RSL), |
| 281 | | maplist(print_runtime_profile_info,RSL), |
| 282 | | findall(WT2,relevant_total_runtime(_PP1,Cat,_RT1,WT2,_Calls,_MaxWT1,_MaxID1,_),WList), |
| 283 | | sumlist(WList,TotalWT), |
| 284 | | findall(Calls2,relevant_total_runtime(_PP2,Cat,_RT2,WT2,Calls2,_MaxWT2,_MaxID2,_),WList2), |
| 285 | | sumlist(WList2,TotalCalls), |
| 286 | | format(' Total Walltime: ~w ms for #calls ~w~n',[TotalWT,TotalCalls]). |
| 287 | | |
| 288 | | print_runtime_profile_info(profile(RT,WT,NrCalls,MaxWT,PP,Cat,MaxID,Min)) :- |
| 289 | | translate_pp(PP,Cat,PPS), |
| 290 | | (MaxID=unknown |
| 291 | | -> format(' ~w : ~w ms (~w ms walltime & ~w - ~w ms walltime; #calls ~w)~n', |
| 292 | | [PPS,RT,WT,Min,MaxWT,NrCalls]) |
| 293 | | ; format(' ~w : ~w ms (~w ms walltime & ~w - ~w ms walltime (max for ~w); #calls ~w)~n', |
| 294 | | [PPS,RT,WT,Min,MaxWT,MaxID,NrCalls]) |
| 295 | | ). |
| 296 | | |
| 297 | | |
| 298 | | tcltk_get_profile_info(Category, |
| 299 | | list([list([Column1,'Total Runtime','Total Walltime', |
| 300 | | '# Calls','Max. Walltime','Max. Witness ID', 'Min. Walltime'])|L])) :- |
| 301 | | get_category_call_name(Category,Column1), |
| 302 | | findall(profile(RT,WT,Calls,MaxWT,AN,Category,MaxWitnessID,Min), |
| 303 | | relevant_total_runtime(AN,Category,RT,WT,Calls,MaxWT,MaxWitnessID,Min),List), |
| 304 | | sort(List,SL), |
| 305 | | reverse(SL,RSL), |
| 306 | | maplist(get_profile_list,RSL,L). |
| 307 | | |
| 308 | | :- use_module(probsrc(tools_meta),[translate_term_into_atom/2]). |
| 309 | | get_profile_list(profile(RT,WT,Calls,MaxWT,AN,Cat,MaxID,Min),list([PPS,RT,WT,Calls,MaxWT,MaxID,Min])) :- |
| 310 | | translate_pp(AN,Cat,PPS). |
| 311 | | |
| 312 | | :- use_module(state_space,[try_get_unique_constants_state/1, |
| 313 | | is_concrete_constants_state_id/1, is_initial_state_id/1]). |
| 314 | | % can be generated from command-line using -csv prob_constants_profile_info FILE |
| 315 | | tcltk_get_constants_profile_info( |
| 316 | | list([list(['Constant','Kind','@desc', |
| 317 | | 'Computation Runtime (ms)', |
| 318 | | 'Computation Walltime (ms)', 'Propagation Walltime (ms)', |
| 319 | | '# Calls','Other Infos', 'Valued','Det.Value','Instantiates'])|ResL])) :- |
| 320 | | (is_concrete_constants_state_id(_) -> |
| 321 | | (constants_profiling_on -> ResL = L ; ResL = [['Set PROFILING_INFO and PERFORMANCE_INFO preference to TRUE for full infos.']|L]) |
| 322 | | ; is_initial_state_id(_) -> ResL = [['The machine has no constants to analyse!']|L] |
| 323 | | ; ResL = [['No constants values computed yet. SETUP_CONSTANTS first!']|L]), |
| 324 | | findall(ProfileTerm, relevant_cst_profile_entry(ProfileTerm),List), |
| 325 | | sort(List,SL), |
| 326 | | reverse(SL,RSL), |
| 327 | | maplist(get_cprofile_list,RSL,L). |
| 328 | | |
| 329 | | % Legend: |
| 330 | | % Computation Runtime & Walltime: time spent computing the constant defined by an equation |
| 331 | | % Propagation Walltime: time spent evaluating predicates and possibly evaluation dependent values |
| 332 | | % #Calls: should probably be 1 here, unless the constants are non-deterministic |
| 333 | | % Other Infos: avl_set, variable, symbolic, marked_as_expand, automatic_expand, marked_as_symbolic |
| 334 | | % long_closure_expansion: this may only count part of the time spent |
| 335 | | % phase1: this computation occured in the second half of the deterministic propagation phase |
| 336 | | % grounding: this computation occured after the determinate propagation phase of ProB |
| 337 | | % automatic_expand: abstract constant detected to be computed automatically |
| 338 | | % marked_as_expand: constant marked with expand pragma |
| 339 | | % Valued: yes: equation determined value straight away, delayed: was computed in phase0 but required more info, non-det was valued but in non-det phase, NO: no value info available |
| 340 | | % Det. Value: value computed in deterministic propagation phase, or unique value found |
| 341 | | % Instantiates: computing that value triggered computation of this list of other constants |
| 342 | | |
| 343 | | :- use_module(bmachine, [constant_variable_marked_as_memo/1, constant_variable_marked_as_expand/1]). |
| 344 | | :- use_module(b_interpreter_components,[get_det_solution_for_constant_value_kind/2]). |
| 345 | | :- use_module(b_machine_hierarchy,[abstract_constant/2, concrete_constant/2]). |
| 346 | | :- use_module(translate,[translate_bvalue_kind/2]). |
| 347 | | relevant_cst_profile_entry(cprofile(RT,WT,PropWT,Calls,PP,Kind,Ann,Phase,IDInfo,InstItself,ValInfo,InstList)) :- |
| 348 | | (try_get_unique_constants_state(CstState) -> true ; CstState=[]), |
| 349 | | (Category = constant_computation(Phase,IDInfo0), |
| 350 | | relevant_total_runtime(PP,Category,RT,WT,Calls,_MaxWT,_MaxWitnessID,_Min), |
| 351 | | Phase \= propagate_value, |
| 352 | | (abstract_constant(PP,_) -> Kind=abstract ; concrete_constant(PP,_) -> Kind=concrete ; Kind=unknown) |
| 353 | | ; |
| 354 | | (constants_profiling_on -> Phase = no_equation_detected |
| 355 | | ; Phase = '-'), % constants profiling on needed to keep track of all equations (except arith. at the moment) |
| 356 | | RT=0, WT=0, PropWT=0, Calls=0, IDInfo0 = [], |
| 357 | | (abstract_constant(PP,_), Kind=abstract ; concrete_constant(PP,_), Kind=concrete), |
| 358 | | \+ total_runtime(PP,constant_computation(_,_),_,_,_,_,_,_) % we have no profiling info at all for PP |
| 359 | | ), |
| 360 | | (get_det_solution_for_constant_value_kind(PP,DetValInfo) |
| 361 | | -> DetSolFound = true, |
| 362 | | exclude(is_value_info,IDInfo0,IDInfo) |
| 363 | | ; DetValInfo = '-', |
| 364 | | DetSolFound = false, IDInfo0=IDInfo |
| 365 | | ), |
| 366 | | ( (DetSolFound=false ; DetValInfo='LARGE-VALUE'), |
| 367 | | member(bind(PP,CstVal),CstState), translate_bvalue_kind(CstVal,ValInfo) |
| 368 | | -> SolFound=true |
| 369 | | ; ValInfo=DetValInfo, SolFound=DetSolFound |
| 370 | | ), |
| 371 | | % now check whether there are infos about propagation phase: |
| 372 | | (total_runtime(PP,constant_computation(propagate_value,PropInfo),_,PropWT,_,_,_,_) |
| 373 | | -> (member(instantiates(IList),PropInfo) -> |
| 374 | | (select(PP,IList,InstList) |
| 375 | | -> InstItself=yes, % Equation determined directly the value |
| 376 | | % check if we have a long closure expansion entry |
| 377 | | % this has already been counted in the regular entry for the constant computation |
| 378 | | (member(long_closure_expansion,IDInfo), Phase=phase0 -> fail ; true) |
| 379 | | ; (DetSolFound=true -> InstItself = 'delayed' |
| 380 | | ; SolFound=true -> InstItself = 'non-det' |
| 381 | | ; InstItself='NO'), |
| 382 | | InstList=IList) |
| 383 | | ; % no instantiation list stored; performance monitoring not on |
| 384 | | (SolFound=true -> InstItself='-' ; InstItself='NO'), |
| 385 | | InstList = '-' |
| 386 | | ) |
| 387 | | ; PropWT = 0, |
| 388 | | (DetSolFound=true -> InstItself='-' ; InstItself='NO'), |
| 389 | | InstList='-' |
| 390 | | ), |
| 391 | | (constant_variable_marked_as_expand(PP) -> Ann=expand |
| 392 | | ; constant_variable_marked_as_memo(PP) -> Ann=memo |
| 393 | | ; Ann = '' |
| 394 | | ). |
| 395 | | |
| 396 | | get_cprofile_list(cprofile(RT,WT,PropWT,Calls,PP,Kind,Ann,Phase,IDInfo0,InstItself,DetVal,IList), |
| 397 | | list([PP,Kind,Ann,RT,WT,PropWT,Calls,IDInfo,InstItself,DetVal,IList])) :- |
| 398 | | (Phase = phase0 -> IDInfo = IDInfo0 ; IDInfo = [Phase|IDInfo0]). |
| 399 | | % phase: phase0, phase1, grounding, enumeration_finished (from get_waitflags_phase) |
| 400 | | |
| 401 | | |
| 402 | | :- use_module(dotsrc(dot_graph_generator), [gen_dot_graph/3]). |
| 403 | | % can be generated from command-line using -dot constants_profile_graph FILE |
| 404 | | % TODO: improve rendering and then enable in meta_interface |
| 405 | | tcltk_dot_constants_profile_info(File) :- |
| 406 | | gen_dot_graph(File,constant_profile_predicate,constant_instantiates). |
| 407 | | |
| 408 | | constant_profile_predicate(NodeID,SubGraph,NodeDesc,Shape,Style,Color) :- SubGraph=none, |
| 409 | | Category = constant_computation(Phase,_Infos), |
| 410 | | total_runtime(NodeID,Category,_RT,WT,_Calls,_MaxWT,_MaxWitnessID,_Min), |
| 411 | | (abstract_constant(NodeID,_) -> Kind=abstract ; Kind=concrete), |
| 412 | | Phase \= propagate_value, |
| 413 | | Shape = box, |
| 414 | | (total_runtime(NodeID,constant_computation(propagate_value,_),_,WT2,_,_,_,_) |
| 415 | | -> ajoin([NodeID,'\\n ',Kind,'\\n ',Phase,'\\n',WT, ' ms','\\n + ',WT2, ' ms'],NodeDesc) |
| 416 | | ; ajoin([NodeID,'\\n ',Kind,'\\n ',Phase,'\\n',WT, ' ms'],NodeDesc) |
| 417 | | ), |
| 418 | | Style='rounded', Color=gray90. |
| 419 | | |
| 420 | | constant_instantiates(NodeID,Label,SuccID,Color,Style) :- |
| 421 | | Color=red4, Style=solid, Label = 'inst', |
| 422 | | Category = constant_computation(Phase,Infos), Phase = propagate_value, |
| 423 | | total_runtime(NodeID,Category,_RT,_WT,_Calls,_MaxWT,_MaxWitnessID,_Min), |
| 424 | | member(instantiates(List),Infos), |
| 425 | | member(SuccID,List), SuccID \= NodeID. |
| 426 | | |
| 427 | | |
| 428 | | :- endif. |