Habitat predictions take an unusually long time for transformer

[michaelshin]

After running tests, I noticed that Transformer takes an long time. Note that I only observed this for T4/V100 GPUs

Here is the log for transformer

stderr /opt/conda/lib/python3.8/site-packages/torch/cuda/memory.py:282: FutureWarning: torch.cuda.reset_max_memory_allocated now calls torch.cuda.reset_peak_memory_stats, which resets /all/ peak memory stats.
stderr   warnings.warn(
stderr 2022-12-22 19:08 INFO     Skyline interactive profiling session started! Listening on port 60120.
stderr 2022-12-22 19:08 INFO     Project Root:  /workspace/ml_tools_test/ml_tools_test/test_models/transformer
stderr 2022-12-22 19:08 INFO     Entry Point:   entry_point.py
Received message of length 205
new message. total: 1
total time is 2.7277989748399705
Received message of length 22585
new message. total: 2
total time is 46.452650535153225
Received message of length 78
new message. total: 3
total time is 9.933224212843925
Received message of length 104
new message. total: 4
total time is 707.5594325081911

For comparison, here is the log for densenet

stderr 2022-12-22 19:05 INFO     Skyline interactive profiling session started! Listening on port 60120.
stderr 2022-12-22 19:05 INFO     Project Root:  /workspace/ml_tools_test/ml_tools_test/test_models/densenet
stderr 2022-12-22 19:05 INFO     Entry Point:   entry_point.py
Received message of length 202
new message. total: 1
total time is 2.679952011909336
Received message of length 2152
new message. total: 2
total time is 27.73253683000803
Received message of length 78
new message. total: 3
total time is 8.593907973030582
Received message of length 104
new message. total: 4
total time is 24.75442389305681

[michaelshin]

I did more profiling and found where the bottleneck was occurring. Here is a truncated sample of the profiling. Note that the exclamation marks have been added to highlight where the bottleneck occurs.

stdout MSHIN DEBUG: starting habitat predictions
stdout MSHIN DEBUG habitat_predict: detected source device T4
stdout MSHIN DEBUG: elapsed time is 0.03131440607830882
stdout MSHIN DEBUG habitat_predict: computed threshold
stdout MSHIN DEBUG elapsed time is 3.9830655632540584
!!! stdout MSHIN DEBUG habitat_predict: ran tracker iterations !!!
!!! stdout MSHIN DEBUG elapsed time is 429.4381717792712 !!!
stdout MSHIN DEBUG habitat_predict: tracing on origin device
stdout MSHIN DEBUG: elapsed time is 429.4390290719457
stdout MSHIN DEBUG habitat_predict: predicting for DeviceProperties(name=P4000)
stdout MSHIN DEBUG: elapsed time is 430.8364302353002
stdout MSHIN DEBUG habitat_predict: predicting for DeviceProperties(name=P100)
stdout MSHIN DEBUG: elapsed time is 432.1802342310548
stdout MSHIN DEBUG habitat_predict: predicting for DeviceProperties(name=V100)
stdout MSHIN DEBUG: elapsed time is 433.4261820060201
stdout MSHIN DEBUG habitat_predict: predicting for DeviceProperties(name=T4)
stdout MSHIN DEBUG: elapsed time is 433.42652934929356
stdout MSHIN DEBUG habitat_predict: predicting for DeviceProperties(name=RTX2070)
stdout MSHIN DEBUG: elapsed time is 434.6849834243767
stdout MSHIN DEBUG habitat_predict: predicting for DeviceProperties(name=RTX2080Ti)
stdout MSHIN DEBUG: elapsed time is 436.0276091359556
stdout MSHIN DEBUG: finishined habitat predictions!
stdout MSHIN DEBUG: elapsed time is 436.02762963902205
stdout MSHIN DEBUG: Finished Habitat analysis 436.0294366800226 seconds
stdout MSHIN DEBUG: Sent habitat response in 436.02969863498583 seconds

That line correspond to the following line in skyline/analysis/session.py

class AnalysisSession:
    ...
    def habitat_predict(self)
        ...

        with tracker.track():
            iteration(*inputs)

        ...

Note that even though this is called in Skyline, the implementation is done in Habitat. I have the original profiling logs if that is helpful as well.

[jimgao1]

This behaviour is observed when I ran Habitat evaluations for new devices - some take a long time and some are killed due to OOM. For now, let us skip this test and investigate further later.

[michaelshin]

Which devices should I skip? I assume T4 and V100. Are there other devices that you saw this behaviour?