Skip to content

timer

util.timer

timer_timer module-attribute 

timer_timer = Timer(devices='cpu', print_elapsed=False, is_enabled=True)

cpu_timer module-attribute 

cpu_timer = Timer(devices='cpu', print_elapsed=False, is_enabled=True)

cuda_timer module-attribute 

cuda_timer = Timer(devices='cuda', print_elapsed=False, is_enabled=True)

test_time module-attribute 

test_time = 1000

BaseTimer 

BaseTimer()

Bases: ABC

Source code in SaigeToolkit/util/timer.py 
13
14
def __init__(self) -> None:
    self._accumulated_time = 0.0

_accumulated_time instance-attribute 

_accumulated_time = 0.0

device_name property 

device_name

accumulated_time property 

accumulated_time

_start_record abstractmethod 

_start_record() -> None

시간 측정을 시작하는 함수를 구현하면 됩니다.

Source code in SaigeToolkit/util/timer.py 
16
17
18
19
@abstractmethod
def _start_record(self) -> None:
    """시간 측정을 시작하는 함수를 구현하면 됩니다."""
    pass

_end_record abstractmethod 

_end_record() -> Union[int, float]

시간 측정을 마치고 걸린 시간을 return 하는 함수를 구현하면 됩니다.

Source code in SaigeToolkit/util/timer.py 
21
22
23
24
@abstractmethod
def _end_record(self) -> Union[int, float]:
    """시간 측정을 마치고 걸린 시간을 return 하는 함수를 구현하면 됩니다."""
    pass

reset 

reset()
Source code in SaigeToolkit/util/timer.py 
34
35
def reset(self):
    self._accumulated_time = 0.0

_CpuTimer 

_CpuTimer()

Bases: BaseTimer

Source code in SaigeToolkit/util/timer.py 
39
40
41
42
43
def __init__(self) -> None:
    super().__init__()
    self._device_name = "CPU"
    self.start = self._get_time_milliseconds()
    self.end = self._get_time_milliseconds()

_device_name instance-attribute 

_device_name = 'CPU'

start instance-attribute 

start = _get_time_milliseconds()

end instance-attribute 

end = _get_time_milliseconds()

_start_record 

_start_record() -> None
Source code in SaigeToolkit/util/timer.py 
45
46
def _start_record(self) -> None:
    self.start = self._get_time_milliseconds()

_end_record 

_end_record() -> Union[int, float]
Source code in SaigeToolkit/util/timer.py 
48
49
50
def _end_record(self) -> Union[int, float]:
    self.end = self._get_time_milliseconds()
    return self.end - self.start

_get_time_milliseconds staticmethod 

_get_time_milliseconds() -> float
Source code in SaigeToolkit/util/timer.py 
52
53
54
@staticmethod
def _get_time_milliseconds() -> float:
    return time.perf_counter() * 1000

_CudaTimer 

_CudaTimer(devices: List[device])

Bases: BaseTimer

Source code in SaigeToolkit/util/timer.py 
58
59
60
61
62
63
64
65
66
def __init__(self, devices: List[torch.device]) -> None:
    super().__init__()
    self._device_name = "CUDA"
    self.devices = devices
    self.streams = [
        torch.cuda.current_stream(device) for device in self.devices if device.type == "cuda"
    ]
    self.start = [torch.cuda.Event(enable_timing=True) for _ in range(len(self.streams))]
    self.end = [torch.cuda.Event(enable_timing=True) for _ in range(len(self.streams))]

_device_name instance-attribute 

_device_name = 'CUDA'

devices instance-attribute 

devices = devices

streams instance-attribute 

streams = [current_stream(device) for device in devices if type == 'cuda']

start instance-attribute 

start = [Event(enable_timing=True) for _ in range(len(streams))]

end instance-attribute 

end = [Event(enable_timing=True) for _ in range(len(streams))]

_start_record 

_start_record() -> None
Source code in SaigeToolkit/util/timer.py 
68
69
70
def _start_record(self) -> None:
    for start, stream in zip(self.start, self.streams):
        start.record(stream=stream)

_end_record 

_end_record() -> Union[int, float]
Source code in SaigeToolkit/util/timer.py 
72
73
74
75
76
77
78
79
80
def _end_record(self) -> Union[int, float]:
    elapsed = 0
    for start, end, stream in zip(self.start, self.end, self.streams):
        with torch.cuda.device(stream.device):
            end.record(stream=stream)
            end.synchronize()
            elapsed = max(elapsed, start.elapsed_time(end))

    return elapsed

Timer 

Timer(devices: Union[device, str, list] = 'cuda:0', print_elapsed: bool = False, is_enabled: bool = True)

Bases: ContextDecorator

argument로 받은 device에 따라 _CudaTimer, _CpuTimer 중 하나를 선택해서 시간을 측정합니다. _CpuTimer의 경우 time.perf_counter()으로 시작과 끝 시간을 측정하며 _CudaTimer의 경우 CUDA synchronization을 포함해서 시간을 측정합니다.

_CudaTimer의 경우 CUDA synchronization을 사용하기 때문에, GPU time 측정시 보다 정확하지만, _CpuTimer보다 속도가 느립니다. (1000번 실행시 약 100ms 정도 차이남)

Context Manager로 사용하거나 decorator 형태로 사용할 수 있습니다.

enable, disable 함수를 이용해서 Timer를 켜고 끌수 있으며, is_enable함수를 통해 현재 Timer의 작동여부를 확인할 수 있습니다.

reset 함수를 이용해서 현재까지 측정한 시간을 초기화 할 수 있습니다.

측정 된 시간은 accumulated_time과 time_stack property를 통해 가져올 수 있습니다. Timer를 사용해서 여러번 시간을 측정할 경우 accumulated_time은 측정한 총 시간의 합을 나타내고, time_stack은 List안에 측정된 시간이 각각 들어있습니다.

Example

  1. Context Manager로 사용하는 경우 timer = CudaTimer() for batch in dataloader: with timer: results = model.inference(batch) print(f"{timer.accumulated_time} ms")

  2. Decorator로 사용하는 경우 @CudaTimer(print_elapsed=True) # 함수 실행시 마다 프린트 def my_function(): ...

    my_function_timer = CudaTimer() # 해당 함수 호출시 시간 축적 @my_function_timer def my_function(): ...

    print(f"{my_function_timer.accumulated_time} ms")

Source code in SaigeToolkit/util/timer.py 
125
126
127
128
129
130
131
132
133
134
135
136
def __init__(
    self,
    devices: Union[torch.device, str, list] = "cuda:0",
    print_elapsed: bool = False,
    is_enabled: bool = True,
) -> None:
    self._devices = devices
    self._print_elapsed = print_elapsed
    self._is_enabled = is_enabled
    self._timer = self._build_timer(self._devices)
    self._accumulated_time = 0.0
    self._time_stack = []

_devices instance-attribute 

_devices = devices

_print_elapsed instance-attribute 

_print_elapsed = print_elapsed

_is_enabled instance-attribute 

_is_enabled = is_enabled

_timer instance-attribute 

_timer = _build_timer(_devices)

_accumulated_time instance-attribute 

_accumulated_time = 0.0

_time_stack instance-attribute 

_time_stack = []

accumulated_time property 

accumulated_time: int

time_stack property 

time_stack: List

to_device 

to_device(device: Union[device, str, list])
Source code in SaigeToolkit/util/timer.py 
138
139
140
def to_device(self, device: Union[torch.device, str, list]):
    self._devices = device
    self._timer = self._build_timer(self._devices)

__enter__ 

__enter__()
Source code in SaigeToolkit/util/timer.py 
142
143
144
145
def __enter__(self):
    if self.is_enabled():
        self._timer._start_record()
    return self

__exit__ 

__exit__(*args, **kwargs)
Source code in SaigeToolkit/util/timer.py 
147
148
149
150
151
152
153
def __exit__(self, *args, **kwargs):
    if self.is_enabled():
        elapsed = self._timer._end_record()
        if self._print_elapsed:
            print(f"{self._timer.device_name} Timer: {elapsed} ms")
        self._accumulated_time += elapsed
        self._time_stack.append(elapsed)

reset 

reset() -> None
Source code in SaigeToolkit/util/timer.py 
163
164
165
def reset(self) -> None:
    self._accumulated_time = 0.0
    self._time_stack.clear()

is_enabled 

is_enabled() -> bool
Source code in SaigeToolkit/util/timer.py 
167
168
def is_enabled(self) -> bool:
    return self._is_enabled

enable 

enable() -> None
Source code in SaigeToolkit/util/timer.py 
170
171
def enable(self) -> None:
    self._is_enabled = True

disable 

disable() -> None
Source code in SaigeToolkit/util/timer.py 
173
174
def disable(self) -> None:
    self._is_enabled = False

_build_timer staticmethod 

_build_timer(devices: Union[device, str, list]) -> Union[_CudaTimer, _CpuTimer]
Source code in SaigeToolkit/util/timer.py 
176
177
178
179
180
181
182
183
184
185
@staticmethod
def _build_timer(devices: Union[torch.device, str, list]) -> Union[_CudaTimer, _CpuTimer]:
    if not isinstance(devices, list):
        devices = [devices]
    devices = [torch.device(device) for device in devices]
    is_cuda = all([any([device.type == "cuda" for device in devices]), torch.cuda.is_available()])

    timer = _CudaTimer(devices) if is_cuda else _CpuTimer()

    return timer

InferenceHandlerTimer 

InferenceHandlerTimer()

IAD/SEG/CLS/DET의 InferenceHandler에서 사용되며, 다른 곳에서 사용하려면 get_time, add_time_to_result를 수정해야합니다. 시간 측정을 원하는 함수를 등록하면 해당 함수가 호출 될 때 시간을 측정해주는 class 입니다. TODO: 범용적으로 사용할 수 있는 부분 분리

Warning 1

instance의 함수를 등록하는 경우 해당 instance의 함수에만 timer가 적용되기 때문에 주의가 필요합니다. ex) inference_handler.postprocess.call_method를 등록했을 때, inference_handler.postprocess 변수가 다른 instance로 변경되는 경우 시간이 측정되지 않습니다.

Warning 2

현재 get_time, add_time_to_result의 경우 아래 api 함수에 매우 specific하게 구현되어 있기 때문에, 코드 변경시 주의가 필요합니다. - API.InferenceHandler.infer_and_postprocess - API.InferenceHandler.step_analysis

Warning 3

빠르게 필요한 기능만 구현하느라 등록한 함수를 제거하는 기능은 아직 추가되어 있지 않습니다. 다만 inference_options를 통해 시간 측정 자체를 끄거나 켤 수 있습니다.

Warning 4

현재는 시간 측정 구간에 cuda synchronize가 필요없어서 overhead를 줄이기 위해 CpuTimer를 사용합니다. 이후에 시간을 측정하는 구간이 늘어난다면 이 부분을 고려한 코드 수정이 필요합니다.

Source code in SaigeToolkit/util/timer.py 
214
215
216
def __init__(self) -> None:
    self._check_list = {}
    self._is_enable = self.default_config["outputs"]["time"]

_check_list instance-attribute 

_check_list = {}

_is_enable instance-attribute 

_is_enable = default_config['outputs']['time']

config property 

config: Dict

default_config property 

default_config: Dict

register 

register(key: str, object: Any, func_name: str, device: Union[device, str, list] = 'cpu')
Source code in SaigeToolkit/util/timer.py 
218
219
220
221
222
223
224
225
226
227
228
229
230
def register(
    self,
    key: str,
    object: Any,
    func_name: str,
    device: Union[torch.device, str, list] = "cpu",
):
    if key in self._check_list:
        raise InferenceHandlerTimerDuplicateKeyError
    timer = Timer(devices=device, is_enabled=False)
    func = getattr(object, func_name)
    setattr(object, func_name, timer(func))
    self._check_list[key] = {"key": key, "object": object, "func_name": func_name, "timer": timer}

to_device 

to_device(key: str, device: Union[device, str, list])
Source code in SaigeToolkit/util/timer.py 
232
233
234
235
236
def to_device(self, key: str, device: Union[torch.device, str, list]):
    if key not in self._check_list:
        raise InferenceHandlerTimerKeyNotFoundError
    timer: Timer = self._check_list[key]["timer"]
    timer.to_device(device)

to_device_all 

to_device_all(device: Union[device, str, list])
Source code in SaigeToolkit/util/timer.py 
238
239
240
def to_device_all(self, device: Union[torch.device, str, list]):
    for key in self._check_list.keys():
        self.to_device(key, device)

is_enable 

is_enable() -> None
Source code in SaigeToolkit/util/timer.py 
242
243
def is_enable(self) -> None:
    return self._is_enable

set 

set(outputs: Dict[str, bool], params: Dict)
Source code in SaigeToolkit/util/timer.py 
245
246
247
def set(self, outputs: Dict[str, bool], params: Dict):
    self._is_enable = outputs.pop("time")
    self._enable() if self._is_enable else self._disable()

reset 

reset()
Source code in SaigeToolkit/util/timer.py 
257
258
259
260
def reset(self):
    for check_dict in self._check_list.values():
        timer: Timer = check_dict["timer"]
        timer.reset()

add_time_to_result 

add_time_to_result(predictions: List[Dict]) -> List[Dict]
Source code in SaigeToolkit/util/timer.py 
262
263
264
265
266
267
268
269
270
271
272
273
def add_time_to_result(self, predictions: List[Dict]) -> List[Dict]:
    if self.is_enable():
        times = self._get_time()
        updated_predictions = []
        for prediction, time in zip(predictions, times):
            if "time" in prediction:
                raise KeyError
            updated_predictions.append({**prediction, "time": time})
    else:
        updated_predictions = predictions

    return updated_predictions

_get_time 

_get_time()

현재 등록되어 있는 key 및 특징 - imread_time - ImageLoader class의 call_method 시간을 측정. - 여러 image가 들어오는 경우 각각 측정됨. - step_analysis에서 이전 prediction 결과를 재사용 하는 경우 시간 측정이 안됨. - preprocess_time - PreProcess class의 call_method 시간을 측정. - ImageLoader 시간이 포함되어 있기 때문에 ImageLoader에 들어간 시간을 제외해야함. - 여러 image가 들어오는 경우 한번만 측정됨. (batch 연산 처리) - step_analysis에서 이전 prediction 결과를 재사용 하는 경우 시간 측정이 안됨. - inference_time - infer 함수 시간을 측정. - 여러 image가 들어오는 경우 한번만 측정됨. (batch 연산 처리) - step_analysis에서 이전 prediction 결과를 재사용 하는 경우 시간 측정이 안됨. - post_processing_time - PostProcess의 _apply 시간을 측정. (각 이미지별로 측정하기 위함) - 여러 image가 들어오는 경우 각각 측정됨.

Source code in SaigeToolkit/util/timer.py 
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
def _get_time(self):
    """
    현재 등록되어 있는 key 및 특징
    - imread_time
        - ImageLoader class의 call_method 시간을 측정.
        - 여러 image가 들어오는 경우 각각 측정됨.
        - step_analysis에서 이전 prediction 결과를 재사용 하는 경우 시간 측정이 안됨.
    - preprocess_time
        - PreProcess class의 call_method 시간을 측정.
        - ImageLoader 시간이 포함되어 있기 때문에 ImageLoader에 들어간 시간을 제외해야함.
        - 여러 image가 들어오는 경우 한번만 측정됨. (batch 연산 처리)
        - step_analysis에서 이전 prediction 결과를 재사용 하는 경우 시간 측정이 안됨.
    - inference_time
        - infer 함수 시간을 측정.
        - 여러 image가 들어오는 경우 한번만 측정됨. (batch 연산 처리)
        - step_analysis에서 이전 prediction 결과를 재사용 하는 경우 시간 측정이 안됨.
    - post_processing_time
        - PostProcess의 _apply 시간을 측정. (각 이미지별로 측정하기 위함)
        - 여러 image가 들어오는 경우 각각 측정됨.
    """

    # key별로 time_stack 가져오기
    time_dict = {k: v["timer"].time_stack for k, v in self._check_list.items()}

    # prediction 결과를 재사용 하여 시간 측정이 안되는 경우 (즉 리스트가 비어있는 경우) 0을 추가해줌.
    # 현재는 이런 경우가 step_analysis 함수에서만 발생하며,
    # step_analysis 함수의 경우 image를 한장씩 처리하기 때문에 하나의 0만 추가
    for k, v in time_dict.items():
        if len(v) == 0:
            time_dict[k] = [0.0]

    # 여기까지 처리했을 때, imread_time과 post_processing_time의 time_stack의 길이가 같아야하며,
    # preprocess_time과 inference_time의 time_stack은 길이가 1이어야 함.
    assert len(time_dict["imread_time"]) == len(time_dict["post_processing_time"])
    assert len(time_dict["preprocess_time"]) == len(time_dict["inference_time"]) == 1

    # preprocess_time은 imread_time이 포함되어 있기 때문에 imread_time의 전체 합을 빼줌.
    time_dict["preprocess_time"][0] -= sum(time_dict["imread_time"])

    # preprocess_time과 inference_time을 실제 image 개수에 맞게 변경 (1/n)
    num_of_image = len(time_dict["imread_time"])
    for key, time_stack in time_dict.items():
        if key in ["preprocess_time", "inference_time"]:
            new_time_stack = [time_stack[0] / num_of_image for _ in range(num_of_image)]
            time_dict[key] = new_time_stack

    # preprocess_time은 따로 저장하지 않고 inference_time에 포함시키기로 기획에서 결정.
    time_dict["inference_time"] = [
        preprocess_time + inference_time
        for preprocess_time, inference_time in zip(
            time_dict["preprocess_time"],
            time_dict["inference_time"],
        )
    ]

    # 사용되지 않는 preprocess_time 제거
    time_dict.pop("preprocess_time")

    # data를 취합하기 쉽도록 구조 변경
    time_list = [{k: v[idx] for k, v in time_dict.items()} for idx in range(num_of_image)]

    return time_list

_enable 

_enable()
Source code in SaigeToolkit/util/timer.py 
338
339
340
341
def _enable(self):
    for check_dict in self._check_list.values():
        timer: Timer = check_dict["timer"]
        timer.enable()

_disable 

_disable()
Source code in SaigeToolkit/util/timer.py 
343
344
345
346
def _disable(self):
    for check_dict in self._check_list.values():
        timer: Timer = check_dict["timer"]
        timer.disable()

_make_config staticmethod 

_make_config(measure_time)
Source code in SaigeToolkit/util/timer.py 
348
349
350
@staticmethod
def _make_config(measure_time):
    return {"outputs": {"time": measure_time}}

with_cpu_timer 

with_cpu_timer()
Source code in SaigeToolkit/util/timer.py 
358
359
360
@cpu_timer
def with_cpu_timer():
    time.sleep(0.001)

with_cuda_timer 

with_cuda_timer()
Source code in SaigeToolkit/util/timer.py 
362
363
364
@cuda_timer
def with_cuda_timer():
    time.sleep(0.001)

timer_test 

timer_test(func, test_time)
Source code in SaigeToolkit/util/timer.py 
366
367
368
369
@timer_timer
def timer_test(func, test_time):
    for _ in range(test_time):
        func()