torch.profiler warmup options and documentation

[minhoolee]

I'm using torch.profiler to profile model inference. When I first started using the profiler, I was very confused the overall inference time to be ~20x higher than it should be. At the time, I was manually warming up my model by running the model before profiling. I later discovered that the large initial latency was a result of not warming up through the profiler after looking into the source code of torch.profiler and seeing that _default_schedule_fn causes torch.profiler to record without warming up.

This doesn't seem obvious considering that the documentation and tutorial demonstrate code snippets that do not warmup. For example,

with profile(activities=[ProfilerActivity.CPU], record_shapes=True) as prof:
    with record_function("model_inference"):
        model(inputs)

The only mention of the need for warming up is step 8 of the tutorial, which is for scheduling on iterations. For code snippets such as the one above, it's not clear how to warmup.

My hacky workarounds look like this:

    with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
        schedule=lambda step: torch.profiler.ProfilerAction.WARMUP,
    ) as prof:
        // Code to profile

    with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
    ) as prof:
        // Code to profile

   with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
        schedule=torch.profiler.schedule(
            wait=0,
            warmup=1,
            active=1,
        ),
    ) as prof:
        for iter in range(2):
            // Code to profile
            prof.step()

Is there a better solution for warming up a single code block to execute? Could the need for warming up be made more explicitly clear in the documentation and tutorial?

Sorry if this issue would be more appropriate in the PyTorch repository. It seems like it would take longer for a response considering there are 5k+ issues.

[minhoolee]

To elaborate on my question, is there a way to explicitly warm up the profiler, so that I could warm it up during initialization? I would like to be able to use the concise 1 line format of

with profile(...) as prof:
    // Code to profile

without needing to add torch.profiler.schedule, a for loop, and prof.step().

It seems like the warmup overhead is from lazy loading CUPTI tracing structures as noted here and here. Is my interpretation correct? Is it possible to eager load the warmup overhead?

[minhoolee]

Hi @gaoteng-git, do you know of a way to eager load the warmup overhead, so that I can use the 1-line context manager (without looping) for inference?

[gaoteng-git]

@minhoolee I think both of your 2 workarounds will take no effect. The real profiling after that still needs warmup. Because the current profiler's context manager will stop CUPTI on exit, so you have to re-warmup it in next usage.
As far as I know, there is no support for warmup without step. You have to carefully check pytorch/torch/profiler/profiler.py code and call the underlying interface directly without using the provided context manager.
Another workaround hack is warp both of your initialization code and desired profiled code under the same profiler context manager(or using __enter__ and __exit__ to discard context manager usage). Set warmup as 1 or 2. Inside it, firstly start a loop with step to do initialization, and then do real inference, as below:

   with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
        schedule=torch.profiler.schedule(
            wait=0,
            warmup=2,
            active=1,
        )
    ) as prof:
        for iter in range(2):
            // Code of initialization
            prof.step()
        
        // Code of inference to profile
        // ...

Yes, the warmup phase is running CUPTI to warmup CUPTI but does not dump to show as result.
Your scenario is profiling model inference, which does not have a loop as training, right? So this requirement is enabling warmup without binding with loop and step, right?
Cool! Thank you very much for your valuable feedback! We'll evaluate it and we may consider support it in future release.

[minhoolee]

Sorry if it wasn't clear. In my workarounds, the // Code to profile is a placeholder for the actual code to profile, not just a comment. I believe both workarounds work, but I'm looking for a different solution.

My use case is to use torch.profiler on any block of code with PyTorch operators in it. The requirement is that this block of code may not have any loops, and it cannot be required that loops are added around it. An example could be model inference on one batch. I would like to use the profiler as a single context manager around the block like so:

with profile(...) as prof:
    // Block of code

I'm currently able to do this, but the timing is completely off because of the profiling warmup overhead. To be clear, does this mean that torch.profiler currently requires schedule, a loop, and prof.step() to avoid warmup overhead?

[minhoolee]

To probe further, is the issue that the profiler's context manager stops CUPTI on exit or that CUPTI needs to be warmed up on the block of code to profile? I found that if I try to warmup on a noop, it doesn't warmup the CUPTI structures.

You have to carefully check pytorch/torch/profiler/profiler.py code and call the underlying interface directly without using the provided context manager.

Does this mean it's possible to explicitly warmup CUPTI once and avoid stopping it? Any sort of pointers on a potential solution, even a hacky one, would be greatly appreciated. Thanks for the help, once again!

[gaoteng-git]

Got it! It's a valuable use case. We will think about support it then.

Please refer to code above. I've updated it with a code.

The key point is each restart of CUPTI will lead to CUPTI warmup overhead, and profiler context manager will stop CUPTI on __exit__ and start CUPTI on entering next context manager object's "warmup“ phase. So if the second context manager doesn't specify "warmup" phase, the CUPTI warmup overhead will be counted into "active" phase, making profiled result not accurate(firstly CUDA call is too time consuming, as below).

[gaoteng-git]

@gdankel A valuable feature enhancement feedback. We may consider support warmup without loop and "step".

[minhoolee]

Thanks, I very much appreciate it! Just to be perfectly clear,

The following's first context manager correctly warmups the second context manager:

    with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
        schedule=lambda step: torch.profiler.ProfilerAction.WARMUP,
    ):
        run_model()

    with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
    ) as prof:
        run_model()

The following's first context manager doesn't warmup the second context manager.

    with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
        schedule=lambda step: torch.profiler.ProfilerAction.WARMUP,
    ):
        pass

    with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
    ) as prof:
        run_model()

My ideal use case would look something like the following:

    torch.profiler.warmup()

    with torch.profiler.profile(
        activities=[
            ProfilerActivity.CPU,
            ProfilerActivity.CUDA,
        ],
    ) as prof:
        run_model()

[gdankel]

We discussed in the past a separate warmup-pass where instead of passing in a schedule you can pass in a lambda for example, with some code resembling the code you want to profile. Cc @ilia-cher

Profiler init overhead is definitely an issue - I think the first is the worst btw, subsequent are not quite as bad.
We need to explore this better and maybe find some creative workarounds.

FIY CUDA11.3 is meant to reduce profiling overheads in general, but haven't yet been able to test.