Variation of GPU energy consumption measurement

[Sunt-ing]

I use the following code adopted from Zeus to benchmark GPU energy consumption. I run 10 times for the same task (each about 11 seconds). I find that the time variation is about 0.85% percent while the GPU energy variation is 2.64%. Here, variation means (highest - lowest)/lowest. I only have one NVIDIA 12GB PCI P100.

class GPUPowerMonitor:
    def __init__(
        self,
        update_period: float | None = 0.1,
    ) -> None:
        """
        Args:
            update_period: Update period of the power monitor in seconds.
        """
        pynvml.nvmlInit()

        power_csv = tempfile.mkstemp(suffix=".csv", text=True)[1]
        open(power_csv, "w").close()
        self.power_f = open(power_csv)
        self.power_df_columns = ["time"] + [f"power0"]
        self.power_df = pd.DataFrame(columns=self.power_df_columns)

        # Spawn the power polling process.
        atexit.register(self._stop)
        self.process = mp.get_context("spawn").Process(
            target=_polling_process, args=(power_csv, update_period)
        )
        self.process.start()

    def _stop(self) -> None:
        pynvml.nvmlShutdown()
        if self.process is not None:
            self.process.terminate()
            self.process.join(timeout=1.0)
            self.process.kill()
            self.process = None

    def _update_df(self) -> None:
        """Add rows to the power dataframe from the CSV file."""
        try:
            additional_df = typing.cast(
                pd.DataFrame,
                pd.read_csv(self.power_f, header=None, names=self.power_df_columns),  # type: ignore
            )
        except pd.errors.EmptyDataError:
            return
        self.power_df = self.power_df.dropna(how='all', axis=1)
        additional_df = additional_df.dropna(how='all', axis=1)
        self.power_df = pd.concat([self.power_df, additional_df], axis=0)

    def get_energy(self, start_time, end_time):
        self._update_df()

        end_time = time.time() if end_time is None else end_time
        
        if self.power_df.empty:
            return None

        df = typing.cast(
            pd.DataFrame, self.power_df.query(f"{start_time} <= time <= {end_time}")
        )

        return float(auc(df["time"], df[f"power{0}"])) 


def _polling_process(
    power_csv: str = "power.csv",
    update_period: float = 0.1, # 10 Hz
) -> None:
    try:
        pynvml.nvmlInit()
        nvml_handles = [pynvml.nvmlDeviceGetHandleByIndex(0)]

        # Use line buffering.
        with open(power_csv, "w", buffering=1) as power_f:
            while True:
                power: list[float] = []
                now = time.time()
                for nvml_handle in nvml_handles:
                    power.append(pynvml.nvmlDeviceGetPowerUsage(nvml_handle))
                power_str = ",".join(map(lambda p: str(p / 1000), power))
                power_f.write(f"{now},{power_str}\n")
                if (sleep_time := update_period - (time.time() - now)) > 0:
                    time.sleep(sleep_time)
    except KeyboardInterrupt:
        return
    finally:
        pynvml.nvmlShutdown()

[Sunt-ing]

Any idea about this variation? Thanks for your help! @jaywonchung

[Sunt-ing]

P.S. I used smaller sampling intervals (e.g., 0.05, 0.01 second) but the variation is the same.

[jaywonchung]

Hi @Sunt-ing! I didn't read the code you posted but that energy variation looks normal to me. Some points:

• Both computation time and energy are influenced by GPU frequency over time, but energy is more sensitive (i.e., energy changes more given the same amount of GPU frequency change). And the GPU's frequency goes up and down significantly (autoboosting) based on on the kernels running, temperature, power draw, etc. So naturally, energy has higher variability than time.
• NVIDIA GPU counters that expose power and energy information are quite coarse-grained. So, if you high-speed poll the power counter with nvmlDeviceGetPowerUsage, you will see that the actual power value changes slowly even when the GPU is being utilized. A100, for example, only updates its power counter once every 100 ms. I'm interested in the counter update period for P100 -- It'd be nice if you can let me know in case you've measured it. But all in all, depending on how long actual computation takes, that 100 ms (or longer) granularity can render the energy value derived from the time--power curve inaccurate.

[Sunt-ing]

Hi @jaywonchung, thanks for your analysis and careful reply! Sorry for the late reply. After thinking and testing it for a while, I think the fluctuation indeed exists. One way to mitigate it is by simply running multiple repetitions (3+) to get the average. BTW, in Zeus project, how did you solve the problem? Thanks for your help!

[jaywonchung]

Yeah basically one needs to run the same workload back to back multiple times to get a stable average. Also, I try to warm up the GPU sufficiently (more that what you'd do for typical performance benchmarking) to increase the GPU's temperature.

[Sunt-ing]

Yes, warmup is also important. I currently just warmup for one run. I think I need to increase the times to warmup. Or I need to set a warmup duration instead?

[jaywonchung]

That should depend on your environment, especially in terms of temperature, your cooling environment. I would watch -n0.1 nvidia-smi as I infinitely repeat my workload and monitor temperature. 5 seconds or more is typically what I expect for warmup.

[Sunt-ing]

Thanks for your provided cmd and data. That's really helpful.

[jaywonchung]

Closing discussion for now, but feel free to ask or comment if there's something unclear :)

[jaywonchung]

Um do you mean in the NSDI paper? I'm not sure where idle energy could possibly appear in its problem setup.

[Sunt-ing]

Yes, I mean in your paper. When you count energy consumption reduction, did you exclude the idle energy? For example, when the idle rate is 25W, unoptimized energy rate is 1000W, optimized energy rate is 500W, how did you get the performance improvement number? Thanks for your help~

[jaywonchung]

Running at a lower power will cause slowdowns, and energy is power integrated over time. Say an unoptimized training run draws 1000 W on average and takes an hour. That's 1000 Wh. If you ran the same training run at 500 W and if it caused 1.5x slowdown, energy would be 750 Wh, reducing 25% energy compared to the unoptimized run.

On the other hand, Perseus will have to consider the GPU's power consumption between forward/backward computations. But that's not idle power, but rather power consumed while blocking on P2P/collective communication. We denote that $P_\textrm{blocking}$ in the paper and consider that as part of the job's total energy consumption. See Equation (3) for how exactly.

[Sunt-ing]

Sorry for the late reply. After thinking about it for a while, I finally got you. Thanks for your careful reply!

[jaywonchung]

No problem. Let me know if you have other questions :)

[Sunt-ing]

Hi Jae-won, I initially adopted the GPU monitoring code from Zeus. But later on, I feel tired of managing these codes myself and am going to directly use Zeus to monitor GPU energy consumption. I installed zeus-ml and ran the example code (changed training to sleep) in https://ml.energy/zeus/reference/monitor/energy/ on Cloudlab c240g5. But I got the following error:

(llama) tingsun@c240g5-110227:/data/Caishen$ python tmp.py
Traceback (most recent call last):
  File "/data/Caishen/tmp.py", line 1, in <module>
    from zeus.monitor import ZeusMontior
ImportError: cannot import name 'ZeusMontior' from 'zeus.monitor' (/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/__init__.py)

Thanks for your help!

[Sunt-ing]

Oh, thanks for your help! I then got the following error. If I remember it correctly, that's the reason why I did not directly use zeus to do monitoring at the beginning. Also, I should reported this typo earlier :)

Traceback (most recent call last):
  File "/data/Caishen/tmp.py", line 5, in <module>
    monitor = ZeusMonitor(gpu_indices)
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/energy.py", line 166, in __init__
    self.power_monitor = PowerMonitor(
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/power.py", line 155, in __init__
    update_period = infer_counter_update_period(self.gpu_indices)
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/power.py", line 55, in infer_counter_update_period
    detected_period = _infer_counter_update_period_single(index)
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/power.py", line 86, in _infer_counter_update_period_single
    gpus.getInstantPowerUsage(gpu_index),
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/device/gpu.py", line 734, in getInstantPowerUsage
    return self.gpus[index].getInstantPowerUsage()
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/device/gpu.py", line 293, in wrapper
    return func(*args, **kwargs)
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/device/gpu.py", line 417, in getInstantPowerUsage
    self.handle, [pynvml.NVML_FI_DEV_POWER_INSTANT]
AttributeError: module 'pynvml' has no attribute 'NVML_FI_DEV_POWER_INSTANT'

[jaywonchung]

Hmm, I thought that one would be supported universally but maybe that's not the case. It's this constant in the doc.

• Which version of nvidia-ml-py and CUDA are you running?
• Which GPU is it?

[Sunt-ing]

$ pip show nvidia-ml-py
Name: nvidia-ml-py
Version: 12.535.161
Summary: Python Bindings for the NVIDIA Management Library
Home-page: https://forums.developer.nvidia.com
Author: NVIDIA Corporation
Author-email: nvml-bindings@nvidia.com
License: BSD
Location: /opt/miniconda/envs/llama/lib/python3.10/site-packages
Requires:
Required-by: nvitop, zeus-ml

$ nvcc --version
nvcc: NVIDIA (R) Cuda compiler driver
Copyright (c) 2005-2024 NVIDIA Corporation
Built on Thu_Mar_28_02:18:24_PDT_2024
Cuda compilation tools, release 12.4, V12.4.131
Build cuda_12.4.r12.4/compiler.34097967_0

The GPU is pretty old:

One NVIDIA 12GB PCI P100 GPU

[jaywonchung]

The GPU is old but it should still work AFAIK. Or, can you see if you have pynvml installed? It's a community-maintained python binding for NVML that conflicts with nvidia-ml-py and it's quite buggy. You should make sure you only have nvidia-ml-py and not pynvml.

[Sunt-ing]

Yes, I have installed pynvml (a dependency of my current GPU monitoring module). I just uninstalled pynvml. After reran the example code, I got an error:

[2024-05-07 06:36:51,606] [zeus.device.gpu](gpu.py:917) PyNVML is available and initialized.
[2024-05-07 06:36:51,612] [zeus.monitor.energy](energy.py:150) Monitoring GPU indices [0].
[2024-05-07 06:36:51,612] [PowerMonitor](power.py:151) Monitoring power usage of GPUs [0]
[2024-05-07 06:36:51,612] [zeus.monitor.power](power.py:51) Detected Tesla P100-PCIE-12GB, inferring NVML power counter update period.
[2024-05-07 06:36:52,034] [zeus.monitor.power](power.py:56) Counter update period for Tesla P100-PCIE-12GB is 0.02 s
[2024-05-07 06:36:53,508] [zeus.device.gpu](gpu.py:917) PyNVML is available and initialized.
[2024-05-07 06:36:53,514] [zeus.monitor.energy](energy.py:150) Monitoring GPU indices [0].
[2024-05-07 06:36:53,514] [PowerMonitor](power.py:151) Monitoring power usage of GPUs [0]
[2024-05-07 06:36:53,514] [zeus.monitor.power](power.py:51) Detected Tesla P100-PCIE-12GB, inferring NVML power counter update period.
[2024-05-07 06:36:53,934] [zeus.monitor.power](power.py:56) Counter update period for Tesla P100-PCIE-12GB is 0.02 s
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 116, in spawn_main
    exitcode = _main(fd, parent_sentinel)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 125, in _main
    prepare(preparation_data)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 236, in prepare
    _fixup_main_from_path(data['init_main_from_path'])
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 287, in _fixup_main_from_path
    main_content = runpy.run_path(main_path,
  File "/opt/miniconda/envs/llama/lib/python3.10/runpy.py", line 289, in run_path
    return _run_module_code(code, init_globals, run_name,
  File "/opt/miniconda/envs/llama/lib/python3.10/runpy.py", line 96, in _run_module_code
    _run_code(code, mod_globals, init_globals,
  File "/opt/miniconda/envs/llama/lib/python3.10/runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "/data/Caishen/tmp.py", line 6, in <module>
    monitor = ZeusMonitor(gpu_indices)
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/energy.py", line 166, in __init__
    self.power_monitor = PowerMonitor(
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/power.py", line 170, in __init__
    self.process.start()
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/process.py", line 121, in start
    self._popen = self._Popen(self)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/context.py", line 288, in _Popen
    return Popen(process_obj)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/popen_spawn_posix.py", line 32, in __init__
    super().__init__(process_obj)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/popen_fork.py", line 19, in __init__
    self._launch(process_obj)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/popen_spawn_posix.py", line 42, in _launch
    prep_data = spawn.get_preparation_data(process_obj._name)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 154, in get_preparation_data
    _check_not_importing_main()
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 134, in _check_not_importing_main
    raise RuntimeError('''
RuntimeError:
        An attempt has been made to start a new process before the
        current process has finished its bootstrapping phase.

        This probably means that you are not using fork to start your
        child processes and you have forgotten to use the proper idiom
        in the main module:

            if __name__ == '__main__':
                freeze_support()
                ...

        The "freeze_support()" line can be omitted if the program
        is not going to be frozen to produce an executable.
Exception ignored in atexit callback: <bound method PowerMonitor._stop of <zeus.monitor.power.PowerMonitor object at 0x7ff11acfae00>>
Traceback (most recent call last):
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/power.py", line 175, in _stop
    self.process.terminate()
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/process.py", line 133, in terminate
    self._popen.terminate()
AttributeError: 'NoneType' object has no attribute 'terminate'
[2024-05-07 06:36:54,696] [zeus.utils.framework](framework.py:38) PyTorch with CUDA support is available.
Training took 4.004164218902588 seconds.
Training consumed 0.0 Joules.
GPU 0 consumed 0.0 Joules.

[Sunt-ing]

I just uninstalled pynvml (dependency of my current GPU monitoring module) and got an error:

[2024-05-07 06:36:51,606] [zeus.device.gpu](gpu.py:917) PyNVML is available and initialized.
[2024-05-07 06:36:51,612] [zeus.monitor.energy](energy.py:150) Monitoring GPU indices [0].
[2024-05-07 06:36:51,612] [PowerMonitor](power.py:151) Monitoring power usage of GPUs [0]
[2024-05-07 06:36:51,612] [zeus.monitor.power](power.py:51) Detected Tesla P100-PCIE-12GB, inferring NVML power counter update period.
[2024-05-07 06:36:52,034] [zeus.monitor.power](power.py:56) Counter update period for Tesla P100-PCIE-12GB is 0.02 s
[2024-05-07 06:36:53,508] [zeus.device.gpu](gpu.py:917) PyNVML is available and initialized.
[2024-05-07 06:36:53,514] [zeus.monitor.energy](energy.py:150) Monitoring GPU indices [0].
[2024-05-07 06:36:53,514] [PowerMonitor](power.py:151) Monitoring power usage of GPUs [0]
[2024-05-07 06:36:53,514] [zeus.monitor.power](power.py:51) Detected Tesla P100-PCIE-12GB, inferring NVML power counter update period.
[2024-05-07 06:36:53,934] [zeus.monitor.power](power.py:56) Counter update period for Tesla P100-PCIE-12GB is 0.02 s
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 116, in spawn_main
    exitcode = _main(fd, parent_sentinel)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 125, in _main
    prepare(preparation_data)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 236, in prepare
    _fixup_main_from_path(data['init_main_from_path'])
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 287, in _fixup_main_from_path
    main_content = runpy.run_path(main_path,
  File "/opt/miniconda/envs/llama/lib/python3.10/runpy.py", line 289, in run_path
    return _run_module_code(code, init_globals, run_name,
  File "/opt/miniconda/envs/llama/lib/python3.10/runpy.py", line 96, in _run_module_code
    _run_code(code, mod_globals, init_globals,
  File "/opt/miniconda/envs/llama/lib/python3.10/runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "/data/Caishen/tmp.py", line 6, in <module>
    monitor = ZeusMonitor(gpu_indices)
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/energy.py", line 166, in __init__
    self.power_monitor = PowerMonitor(
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/power.py", line 170, in __init__
    self.process.start()
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/process.py", line 121, in start
    self._popen = self._Popen(self)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/context.py", line 288, in _Popen
    return Popen(process_obj)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/popen_spawn_posix.py", line 32, in __init__
    super().__init__(process_obj)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/popen_fork.py", line 19, in __init__
    self._launch(process_obj)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/popen_spawn_posix.py", line 42, in _launch
    prep_data = spawn.get_preparation_data(process_obj._name)
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 154, in get_preparation_data
    _check_not_importing_main()
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/spawn.py", line 134, in _check_not_importing_main
    raise RuntimeError('''
RuntimeError:
        An attempt has been made to start a new process before the
        current process has finished its bootstrapping phase.

        This probably means that you are not using fork to start your
        child processes and you have forgotten to use the proper idiom
        in the main module:

            if __name__ == '__main__':
                freeze_support()
                ...

        The "freeze_support()" line can be omitted if the program
        is not going to be frozen to produce an executable.
Exception ignored in atexit callback: <bound method PowerMonitor._stop of <zeus.monitor.power.PowerMonitor object at 0x7ff11acfae00>>
Traceback (most recent call last):
  File "/opt/miniconda/envs/llama/lib/python3.10/site-packages/zeus/monitor/power.py", line 175, in _stop
    self.process.terminate()
  File "/opt/miniconda/envs/llama/lib/python3.10/multiprocessing/process.py", line 133, in terminate
    self._popen.terminate()
AttributeError: 'NoneType' object has no attribute 'terminate'
[2024-05-07 06:36:54,696] [zeus.utils.framework](framework.py:38) PyTorch with CUDA support is available.
Training took 4.004164218902588 seconds.
Training consumed 0.0 Joules.
GPU 0 consumed 0.0 Joules.

[jaywonchung]

Are you instantiating the ZeusMonitor as a global variable without protecting it with if __name__ == "__main__"? Since it has to spawn a power polling process on older architectures, it can be a problem. See also the end of the docstring: https://ml.energy/zeus/reference/monitor/energy/#zeus.monitor.energy.ZeusMonitor

[Sunt-ing]

Yes, and now it works! Thanks for your help!

My current script:

from zeus.monitor import ZeusMonitor
import time

if __name__ == "__main__":
    # Time/Energy measurements for four GPUs will begin and end at the same time.
    gpu_indices = [0]
    monitor = ZeusMonitor(gpu_indices)

    # Mark the beginning of a measurement window. You can use any string
    # as the window name, but make sure it's unique.
    monitor.begin_window("entire_training")

    # Actual work
    time.sleep(4)

    # Mark the end of a measurement window and retrieve the measurment result.
    result = monitor.end_window("entire_training")

    # Print the measurement result.
    print(f"Training took {result.time} seconds.")
    print(f"Training consumed {result.total_energy} Joules.")
    for gpu_idx, gpu_energy in result.energy.items():
        print(f"GPU {gpu_idx} consumed {gpu_energy} Joules.")

[Sunt-ing]

BTW, what's the best practice of multiple GPU energy measurements in a single program? Shall I initiate a new ZeusMonitor before each measurement?

[jaywonchung]

Could you create new discussion threads for independent questions? All your questions are very good, and I want other people to discover your questions when they look at the discussion tab. But for this one:

It all depends on how multiple GPUs are being used in your application, so I'll just talk about two general ways of doing it:

1. Giving a list of all GPU indices as gpu_indices. This is a centralized approach where the Rank 0 process can handle measurements for all GPUs. In this case, the measurement window for all GPUs are synchronized (i.e., the window begins and ends at the same time for every GPU in gpu_indices). For stuff like data parallel training, this should be what users want.

   if torch.distributed.get_rank() == 0:
       monitor = ZeusMonitor(gpu_indices=[0, 1, 2, 3])
   
   if torch.distributed.get_rank() == 0:
       monitor.begin_window("entire_training")

2. Another way is to instantiate a monitor for each process that manages one GPU. For this one, you will need a way to aggregate measurements across all GPUs.

   monitor = ZeusMonitor(gpu_indices=[torch.cuda.current_device()])
   
   # Obtained `measurement` object in this rank
   
   measurements = [None for _ in range(4)]
   torch.distributed.all_gather_object(measurements, obj=measurement)

[Sunt-ing]

Sorry for not making my question clear and thanks for your suggestions. Here is my real question: #74