U PhA>@s`ddlmZddlZddlZddlZddlZddlZddlZddlm Z m Z ddl m Z ddl mZddlmZmZddlmZddlmZmZdd lmZmZmZddlZddlZdd lmZerdd l m!Z!n ed d dZ!ed\Z"Z#dddddddgZ$ddZ%ddZ&ddZ'GdddZ(e dddddd d!gZ)d"dZ*Gd#ddZ+Gd$ddZ,dS)%) annotationsN) defaultdict namedtuple)contextmanagerwraps) getframeinfostack)Empty) perf_counterperf_counter_ns) TYPE_CHECKINGAnycast)optional_import)Eventsz ignite.enginer)namepandastorch_profiler_fulltorch_profiler_time_cpu_gputorch_profiler_time_end_to_end PerfContextWorkflowProfilerProfileHandlerselect_transform_callcstfdd}|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. c s6tjjjdd}||}W5QRXt|dd|S)NTuse_cudaflush)torchautogradprofilerprofileprint)argskwargsprofresultfuncJ/home/dell461/cl/sdc2/HISourceFinder-master-l/src/monai/utils/profiling.pywrapper:s z$torch_profiler_full..wrapperrr)r,r*r(r+r3scstfdd}|S)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. c sxtjjjdd}||}W5QRX|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) rr 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+rFscstfdd}|S)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. csZtjt}||}tjt}||d}tjj|}td|dd|S)Ng.AzEnd-to-end time: Tr)rcuda synchronizer r r!r6r#)r$r%startr'end total_timeZtotal_time_strr(r*r+r,fs    z/torch_profiler_time_end_to_end..wrapperrr-r*r(r+r_sc@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__szPerfContext.__init__cCs t|_|Sr.)r r=r>r*r*r+ __enter__szPerfContext.__enter__cCs*|jdk r |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__r@rArEr*r*r*r+rys ProfileResultrtimefilenamelinenopid timestampcCs0ddlm}|jdd}|jjdko.t||S)zMReturns True if `frame` is a call to a `Transform` object's `_call__` method.r) Transformr?N__call__)monai.transformsrPf_localsgetf_codeco_name isinstance)framerPself_objr*r*r+rs c@seZdZdZefddZddZddZdd Zd d Z d d Z ddZ ddZ dddddZ ddZed'ddZd(ddZddZd)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?rfr*r*r+r@s    zWorkflowProfiler.__init__cCst|jkS)z*Return True if this is the parent process.)r\r]r^r>r*r*r+ _is_parentszWorkflowProfiler._is_parentcCs|jdk p|j S)z6Return True if the read thread should be still active.N)r_reemptyr>r*r*r+_is_thread_activesz"WorkflowProfiler._is_thread_activecCsf|rL|rLz$|j}|dkr(WqL||Wqtk rHYqXq|rb|jsbtdS)zVRead results from the queue and add to self.results in a thread stared by `__enter__`.N)rgrirerT add_resultr rhAssertionErrorr?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)strdatetimenowreputrJr\r])r?r timedeltarLrMtsr*r*r+ _put_resultszWorkflowProfiler._put_resultcs<|dkr2|r8|tfdd}|SnjSdS)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. callcs`|dkr\t}j}jdd}|j}|dk rHt|jd|}|||j|j dS)z6Defines a new inner trace function just for this call.returnr?N.) r rUrSrTrVtyperFrt co_filenameco_firstlineno)rXwhyargdiffrUrYr calling_framer?r:r*r+_call_profilers z4WorkflowProfiler._trace_call.._call_profilerN)rfr _trace_call)r?rXr{r|rr*r~r+rs zWorkflowProfiler._trace_callcCs@tj|jd|_|j|jdk rr*r*r+rAs     zWorkflowProfiler.__enter__cCsV|s t|jdttj|j}d|_||j dk rRt dt ddS)z>Terminate the read thread cleanly and reset tracing if needed.N) rgrkrerqrr`rr_joinrfrr)r?rBrC tracebackr_r*r*r+rEs   zWorkflowProfiler.__exit__rJNone)r'rvc Cs(|j|j|j|W5QRXdS)zHAdd a result in a thread-safe manner to the internal results dictionary.N)rbr[rappendrlr*r*r+rj)szWorkflowProfiler.add_resultc CsB|std|j"dd|jDW5QRSQRXdS)zPGet a fresh results dictionary containing fresh tuples of ProfileResult objects.z'Only parent process can collect resultscSsi|]\}}|t|qSr*)tuple)r0kvr*r*r+ 4sz0WorkflowProfiler.get_results..N)rg RuntimeErrorrbr[itemsr>r*r*r+ get_results.szWorkflowProfiler.get_resultsNc csP|dkrttdd}t}z dVW5t|}||||j|jXdS)zSCreates a context to profile, placing a timing result onto the queue when it exits.Nr)rr r rtrLrM)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 dkr|jn}||Sr.)rFr)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.._Iterablec3sxd}t}ttdd}|rtz6t}t|}t|}||j|j|VWqtk rpd}YqXqdS)NTrF) iterrr r nextrtrLrM StopIteration)_selfZdo_iterZ orig_iterrr:itemr}iterablerr?r*r+__iter__Ts  z9WorkflowProfiler.profile_iter.._Iterable.__iter__N)rFrGrHrr*rr*r+ _IterableRsrr*)r?rrrr*rr+ profile_iterOszWorkflowProfiler.profile_iterTc si}|D]l\}}|r dndfdd|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*)rK)r0resZtimemultr*r+ nsz6WorkflowProfiler.get_times_summary..)rrr4lennpstdminmax) r? times_in_sr'rrZ all_timesZtimesumZtimeavgZtimestdZtimeminZtimemaxr*rr+get_times_summaryfs   z"WorkflowProfiler.get_times_summarycCs^ddl}||}|rdnd}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?rpdsummsuffixrdfr*r*r+get_times_summary_pdzs  z%WorkflowProfiler.get_times_summary_pdcCs\t|}tj||ddd}||D]}|D]}||qBq:dS)zSave all results to a csv file.r) fieldnamesN) rZrvaluescsv DictWriter_asdictkeys writeheaderwriterow)r?streamZ all_resultswriterrlistrr*r*r+dump_csvs zWorkflowProfiler.dump_csv)N)N)T)T)rFrGrHrIrr@rgrirmrtrrArErjrrrrrrrrstdoutrr*r*r*r+rs$/     c@s<eZdZdZdddddddZdd Zd d Zd d ZdS)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 rnrr)rr! start_event end_eventcCs"||_||_||_||_d|_dSr.)rr!rrctx)r?rr!rrr*r*r+r@s zProfileHandler.__init__cCs$||j|j||j|j|Sr.)add_event_handlerrr:rr;r?enginer*r*r+attachszProfileHandler.attachcCs|j|j|_|jdSr.)r!rrrrArr*r*r+r:szProfileHandler.startcCs|jdddd|_dSr.)rrErr*r*r+r;szProfileHandler.endN)rFrGrHrIr@rr:r;r*r*r*r+rs  )- __future__rrrorcr\rr` collectionsrr contextlibr functoolsrinspectrr rer rKr r typingr rrnumpyrr monai.utilsr ignite.enginerrZ has_pandas__all__rrrrrJrrrr*r*r*r+ sJ        x