o  iA>@sNddlmZddlZddlZddlZddlZddlZddlZddlm Z m Z ddl m Z ddl mZddlmZmZddlmZddlmZmZdd lmZmZmZddlZddlZdd lmZeridd l m!Z!ned d dZ!ed\Z"Z#gdZ$ddZ%ddZ&ddZ'GdddZ(e dgdZ)ddZ*GdddZ+Gdd d Z,dS)!) annotationsN) defaultdict namedtuple)contextmanagerwraps) getframeinfostack)Empty) perf_counterperf_counter_ns) TYPE_CHECKINGAnycast)optional_import)Eventsz ignite.enginer)namepandas)torch_profiler_fulltorch_profiler_time_cpu_gputorch_profiler_time_end_to_end PerfContextWorkflowProfilerProfileHandlerselect_transform_callctfdd}|S)z A decorator which will run the torch profiler for the decorated function, printing the results in full. Note: Enforces a gpu sync point which could slow down pipelines. csNtjjjdd}|i|}Wdn1swYt|dd|S)NTuse_cudaflush)torchautogradprofilerprofileprint)argskwargsprofresultfuncW/home/dell461/cl/sdc2/last_ska_mid/HISourceFinder-master-l/src/monai/utils/profiling.pywrapper:s  z$torch_profiler_full..wrapperrr*r-r+r)r,r3srcr)z A decorator which measures the execution time of both the CPU and GPU components of the decorated function, printing both results. Note: Enforces a gpu sync point which could slow down pipelines. cstjjjdd}|i|}Wdn1swY|j}tdd|jD}tjj|}tjj|}td|d|dd|S)NTrcss|]}|jVqdSN)self_cuda_time_total).0evtr+r+r, Ssz?torch_profiler_time_cpu_gpu..wrapper..z cpu time: z , gpu time: r) r r!r"r#self_cpu_time_totalsumfunction_events format_timer$)r%r&r'r(cpu_timeZgpu_timer)r+r,r-Msz,torch_profiler_time_cpu_gpu..wrapperrr.r+r)r,rFsrcr)z A decorator which measures the total execution time from when the decorated function is called to when the last cuda operation finishes, printing the result. Note: Enforces a gpu sync point which could slow down pipelines. cs^tjt}|i|}tjt}||d}tjj|}td|dd|S)Ng.AzEnd-to-end time: Tr)r cuda synchronizer r!r"r7r$)r%r&startr(end total_timeZtotal_time_strr)r+r,r-fs   z/torch_profiler_time_end_to_end..wrapperrr.r+r)r,r_src@s(eZdZdZddZddZddZdS) ra Context manager for tracking how much time is spent within context blocks. This uses `time.perf_counter` to accumulate the total amount of time in seconds in the attribute `total_time` over however many context blocks the object is used in. cCsd|_d|_dS)Nr)r= start_timeselfr+r+r,__init__s zPerfContext.__init__cCs t|_|Sr/)r r>r?r+r+r, __enter__szPerfContext.__enter__cCs*|jdur|jt|j7_d|_dSr/)r>r=r )r@exc_type exc_value exc_tracebackr+r+r,__exit__s  zPerfContext.__exit__N)__name__ __module__ __qualname____doc__rArBrFr+r+r+r,rys  r ProfileResult)rtimefilenamelinenopid timestampcCs0ddlm}|jdd}|jjdkot||S)zMReturns True if `frame` is a call to a `Transform` object's `_call__` method.r) Transformr@N__call__)monai.transformsrQf_localsgetf_codeco_name isinstance)framerQself_objr+r+r,rs rc@seZdZdZefddZddZddZdd Zd d Z d d Z ddZ ddZ d(ddZ ddZed)ddZd)ddZdd Zd*d"d#Zd*d$d%Zejfd&d'ZdS)+rae Profiler for timing all aspects of a workflow. This includes using stack tracing to capture call times for all selected calls (by default calls to `Transform.__call__` methods), times within context blocks, times to generate items from iterables, and times to execute decorated functions. This profiler must be used only within its context because it uses an internal thread to read results from a multiprocessing queue. This allows the profiler to function across multiple threads and processes, though the multiprocess tracing is at times unreliable and not available in Windows at all. The profiler uses `sys.settrace` and `threading.settrace` to find all calls to profile, this will be set when the context enters and cleared when it exits so proper use of the context is essential to prevent excessive tracing. Note that tracing has a high overhead so times will not accurately reflect real world performance but give an idea of relative share of time spent. The tracing functionality uses a selector to choose which calls to trace, since tracing all calls induces infinite loops and would be terribly slow even if not. This selector is a callable accepting a `call` trace frame and returns True if the call should be traced. The default is `select_transform_call` which will return True for `Transform.__call__` calls only. Example showing use of all profiling functions: .. code-block:: python import monai.transform as mt from monai.utils import WorkflowProfiler import torch comp=mt.Compose([mt.ScaleIntensity(),mt.RandAxisFlip(0.5)]) with WorkflowProfiler() as wp: for _ in wp.profile_iter("range",range(5)): with wp.profile_ctx("Loop"): for i in range(10): comp(torch.rand(1,16,16)) @wp.profile_callable() def foo(): pass foo() foo() print(wp.get_times_summary_pd()) # print results Args: call_selector: selector to determine which calls to trace, use None to disable tracing cCs>tt|_t|_d|_t|_ t |_ d|_ ||_dS)Ng?)rlistresultsosgetpid parent_pid read_thread threadingRLocklockmultiprocessing SimpleQueuequeueZ queue_timeout call_selector)r@rgr+r+r,rAs     zWorkflowProfiler.__init__cCst|jkS)z*Return True if this is the parent process.)r]r^r_r?r+r+r, _is_parentszWorkflowProfiler._is_parentcCs|jdup |j S)z6Return True if the read thread should be still active.N)r`rfemptyr?r+r+r,_is_thread_activesz"WorkflowProfiler._is_thread_activecCsv|r,|r,z|j}|durWn||Wn ty#Ynw|r,|s|r7|js9tdSdS)zVRead results from the queue and add to self.results in a thread stared by `__enter__`.N)rhrjrfrU add_resultr riAssertionErrorr@r(r+r+r,_read_thread_funcs   z"WorkflowProfiler._read_thread_funcc Cs0ttj}|jt||||t|dS)z(Add a ProfileResult object to the queue.N)strdatetimenowrfputrKr]r^)r@r timedeltarMrNtsr+r+r, _put_results"zWorkflowProfiler._put_resultcs:|dkr|r|tfdd}|SdSjS)z Trace calls, when a call is encountered that is accepted by self.call_selector, create a new function to trace that call and measure the time from the call to a "return" frame. callcsd|dkr0t}j}jdd}|j}|dur$t|jd|}|||j|j dSdS)z6Defines a new inner trace function just for this call.returnr@N.) r rVrTrUrWtyperGru co_filenameco_firstlineno)rYwhyargdiffrVrZr calling_framer@r;r+r,_call_profilers z4WorkflowProfiler._trace_call.._call_profilerN)rgr _trace_call)r@rYr|r}rr+rr,rs zWorkflowProfiler._trace_callcCs@tj|jd|_|j|jdurt|jt|j|S)zMEnter the context, creating the read thread and setting up tracing if needed.)targetN) raThreadrnr`r;rgsettracersysr?r+r+r,rBs     zWorkflowProfiler.__enter__cCsZ|st|jdttj|j}d|_||j dur+t dt ddSdS)z>Terminate the read thread cleanly and reset tracing if needed.N) rhrlrfrrrrarr`joinrgrr)r@rCrD tracebackr`r+r+r,rFs   zWorkflowProfiler.__exit__r(rKrwNonecCs>|j|j|j|WddS1swYdS)zHAdd a result in a thread-safe manner to the internal results dictionary.N)rcr\rappendrmr+r+r,rk)s"zWorkflowProfiler.add_resultcCsN|std|jdd|jDWdS1s wYdS)zPGet a fresh results dictionary containing fresh tuples of ProfileResult objects.z'Only parent process can collect resultscSsi|] \}}|t|qSr+)tuple)r1kvr+r+r, 4sz0WorkflowProfiler.get_results..N)rh RuntimeErrorrcr\itemsr?r+r+r, get_results.s $zWorkflowProfiler.get_resultsNc csn|durttdd}t}zdVWt|}||||j|jdSt|}||||j|jw)zSCreates a context to profile, placing a timing result onto the queue when it exits.Nr)rr r rurMrN)r@rcallerr;r~r+r+r, profile_ctx6s  zWorkflowProfiler.profile_ctxcsfdd}|S)z Decorator which can be applied to a function which profiles any calls to it. All calls to decorated callables must be done within the context of the profiler. cs dur|jn}||Sr/)rGr)r*_namerr@r+r,_outerIsz1WorkflowProfiler.profile_callable.._outerr+)r@rrr+rr,profile_callableCsz!WorkflowProfiler.profile_callablecsGfddd}|S)zPWrapper around anything iterable to profile how long it takes to generate items.cseZdZfddZdS)z0WorkflowProfiler.profile_iter.._Iterablec3s~d}t}ttdd}|r=zt}t|}t|}||j|j|VWn ty8d}Ynw|sdSdS)NTrF) iterrr r nextrurMrN StopIteration)_selfZdo_iterZ orig_iterrr;itemr~iterablerr@r+r,__iter__Ts    z9WorkflowProfiler.profile_iter.._Iterable.__iter__N)rGrHrIrr+rr+r, _IterableRsrr+)r@rrrr+rr, profile_iterOszWorkflowProfiler.profile_iterTc si}|D]6\}}|rdndfdd|D}t|}|t|}t|}t|} t|} t||||| | f||<q|S)z Returns a dictionary mapping results entries to tuples containing the number of items, time sum, time average, time std dev, time min, and time max. g& .>g?csg|]}|jqSr+)rL)r1resZtimemultr+r, nsz6WorkflowProfiler.get_times_summary..)rrr5lennpstdminmax) r@ times_in_sr(rrZ all_timesZtimesumZtimeavgZtimestdZtimeminZtimemaxr+rr,get_times_summaryfs   z"WorkflowProfiler.get_times_summarycCs^ddl}||}|r dnd}dd|ddd d d g}|jj|d |d }|j|ddd}|S)zNReturns the same information as `get_times_summary` but in a Pandas DataFrame.rNsnsZCountz Total Time ()ZAvgZStdMinMaxindex)orientcolumnsrF) ascending)rr DataFrame from_dict sort_values)r@rpdZsummsuffixrdfr+r+r,get_times_summary_pdzs  z%WorkflowProfiler.get_times_summary_pdcCs\t|}tj||ddd}||D]}|D] }||q!qdS)zSave all results to a csv file.r) fieldnamesN) r[rvaluescsv DictWriter_asdictkeys writeheaderwriterow)r@streamZ all_resultswriterrlistrr+r+r,dump_csvszWorkflowProfiler.dump_csv)r(rKrwrr/)T)rGrHrIrJrrArhrjrnrurrBrFrkrrrrrrrrstdoutrr+r+r+r,rs& /       rc@s2eZdZdZdd d Zd d Zd dZddZdS)rar Handler for Ignite Engine classes which measures the time from a start event ton an end event. This can be used to profile epoch, iteration, and other events as defined in `ignite.engine.Events`. This class should be used only within the context of a profiler object. Args: name: name of event to profile profiler: instance of WorkflowProfiler used by the handler, should be within the context of this object start_event: item in `ignite.engine.Events` stating event at which to start timing end_event: item in `ignite.engine.Events` stating event at which to stop timing rror"r start_eventr end_eventcCs"||_||_||_||_d|_dSr/)rr"rrctx)r@rr"rrr+r+r,rAs  zProfileHandler.__init__cCs$||j|j||j|j|Sr/)add_event_handlerrr;rr<r@enginer+r+r,attachszProfileHandler.attachcCs|j|j|_|jdSr/)r"rrrrBrr+r+r,r;szProfileHandler.startcCs|jdddd|_dSr/)rrFrr+r+r,r<s zProfileHandler.endN)rror"rrrrr)rGrHrIrJrArr;r<r+r+r+r,rs   r)- __future__rrrprdr]rra collectionsrr contextlibr functoolsrinspectrr rfr rLr r typingr rrnumpyrr monai.utilsr ignite.enginerrZ has_pandas__all__rrrrrKrrrr+r+r+r,s>        x