# Meaning of timers in RLlib PPO

**URL:** <https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652>\
**Category:** RLlib\
**Created:** [April 10, 2021, 10:39pm UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652 "2021-04-10T22:39:35Z")\
**Posts on this page:** 7\
**Page:** 1

<div class="post-metadata">

**Author:** ![javigm98](https://sea2.discourse-cdn.com/flex020/user_avatar/discuss.ray.io/javigm98/32/704_2.png) [@javigm98](https://discuss.ray.io/u/javigm98)\
**Post date:** [April 10, 2021, 10:39pm UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652/1 "2021-04-10T22:39:35Z")

</div>

Hi, I have trained a model using PPO and when I see results by iteration (the ones saved in `~/ray_results` and that you can visiually represent with tensorboard) there are some metrics I don’t know exactly what they refer to. Is there any place where these metrics values are explianed? Specifically I’m interested in knowing what each timer represents:

- `timers/sample_time_ms`,
- `timers/sample_throughput`
- `timers/load_time_ms`
- `timers/load_throughput`
- `timers/learn_time_ms`
- `timers/learn_throughput`
- `timers/update_time_ms`

Thanks in advance

---

<div class="post-metadata">

**Author:** ![thomaslecat](https://sea2.discourse-cdn.com/flex020/user_avatar/discuss.ray.io/thomaslecat/32/804_2.png) [@thomaslecat](https://discuss.ray.io/u/thomaslecat)\
**Post date:** [April 14, 2021, 2:54pm UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652/2 "2021-04-14T14:54:27Z")

</div>

Hi @javigm98 ,

I do not think the metrics are documented, but I had the same question so I hopefully can help finding the answer.

`load_time_ms`, `learn_time_ms` and `update_time_ms` are recorded in the method ` __call__ (...)` or ray.rllib.execution.train\_ops.TrainTFMultiGPU with [these](https://github.com/ray-project/ray/blob/bbfa8ffec9affe84db7313930434eeb4208de645/rllib/execution/train_ops.py#L182-L183) and [this](https://github.com/ray-project/ray/blob/bbfa8ffec9affe84db7313930434eeb4208de645/rllib/execution/train_ops.py#L245) timer objects.

If I remember correctly, `lean_time_ms` is the time to compute the gradients and perform one gradient descent step; `load_time_ms` is the time to load the sample on the device that will compute the gradients (GPU(s)); `update_time_ms` is the time to send the new weights of the network to each worker before starting the next iteration.

I don’t remember where `sample_time_ms` is recorded but it is basically the time for workers to collect enough sample for one iteration.

The `_throughput` metrics are computed by the timers (see ray.utils.timer.\_Timer.mean\_throughput) as the number of steps loaded or trained per second during the respective operations.

---

<div class="post-metadata">

**Author:** ![javigm98](https://sea2.discourse-cdn.com/flex020/user_avatar/discuss.ray.io/javigm98/32/704_2.png) [@javigm98](https://discuss.ray.io/u/javigm98)\
**Post date:** [April 14, 2021, 11:01pm UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652/3 "2021-04-14T23:01:32Z")

</div>

Hi @thomaslecat and thank you so much for your answer. It was really clarifying to me!!

---

<div class="post-metadata">

**Author:** ![henry\_lei](https://sea2.discourse-cdn.com/flex020/user_avatar/discuss.ray.io/henry_lei/32/1613_2.png) [@henry\_lei](https://discuss.ray.io/u/henry_lei)\
**Post date:** [October 30, 2021, 4:13am UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652/4 "2021-10-30T04:13:11Z")

</div>

Kind of an iffy question, but what are some good values (in terms of orders of magnitude) for these timers? For example, for a fully connected [64,64] nn, my learn time ms is something like 2000 ms, which feels slow to me. I wasn’t using a gpu, but the network is kind of small, so I’m not sure if my intuition is valid…

---

<div class="post-metadata">

**Author:** ![arturn](https://sea2.discourse-cdn.com/flex020/user_avatar/discuss.ray.io/arturn/32/2096_2.png) [@arturn](https://discuss.ray.io/u/arturn)\
**Post date:** [July 21, 2022, 8:41pm UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652/5 "2022-07-21T20:41:19Z")

</div>

Just putting this here because I answered something similar outside the forums.

All metrics are averaged per iteration of an algorithm. That is, they are averaged per reporting of metrics and generally encompass many SGD steps, sampled batches etc.

/timers/learn\_throughput:  
Number of batches that we have learned on.

/timers/learn\_time\_ms:  
Number of ms it took on average to learn on a single batch. In the case of multiple SGD steps (see num\_sgd\_iter), this spans all SGD steps over a single batch we learn on. In the case of a multi-agent batch, this also spans all SGD steps that might be taken sequentially for the individual policies.

/timers/load\_throughput:  
Number of batches we have loaded. That is, we might decompress a batch, pad it and put it onto the device of the policy that is going to train on the batch. This is independent of other preprocessing steps that might occur as part of the algorithm and therefore excludes per-algorithm logic.

/timers/load\_time\_ms:  
Number of ms it took on average for a batch to be loaded. See above for what loading encompasses.

/timers/training\_iteration\_time\_ms:  
The number of ms it took for the iteration of the algorithm to be completed. This may include things like sampling, SGD steps, or updates of sampling policies.

/timers/update\_time\_ms:  
The number of ms it took to update the sampling policies of all distributed workers after training the policy/policies.

---

<div class="post-metadata">

**Author:** ![stefanbschneider](https://sea2.discourse-cdn.com/flex020/user_avatar/discuss.ray.io/stefanbschneider/32/232_2.png) [@stefanbschneider](https://discuss.ray.io/u/stefanbschneider)\
**Post date:** [June 27, 2023, 9:06am UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652/6 "2023-06-27T09:06:57Z")

</div>

I was also searching for the meaning of some logged metrics regarding timing and found this thread. Some of the metrics have been explained already (thanks @thomaslecat and @arturn ). Some I had to look up in the [source code `_PerfStats`](https://github.com/ray-project/ray/blob/ray-2.3.0/rllib/evaluation/env_runner_v2.py#L90):

```python
# Raw observation preprocessing.
"mean_raw_obs_processing_ms": self.raw_obs_processing_time * factor,
# Computing actions through policy.
"mean_inference_ms": self.inference_time * factor,
# Processing actions (to be sent to env, e.g. clipping).
"mean_action_processing_ms": self.action_processing_time * factor,
# Waiting for environment (during poll).
"mean_env_wait_ms": self.env_wait_time * factor,
# Environment rendering (False by default).
"mean_env_render_ms": self.env_render_time * factor,

```

The comments are not super explanatory, but maybe still helpful for some. @arturn Do you know if `mean_env_wait_ms` includes the environment stepping? Or what happens during the poll? Is there any metric that measures the environment’s speed?

---

<div class="post-metadata">

**Author:** ![Rohan138](https://sea2.discourse-cdn.com/flex020/user_avatar/discuss.ray.io/rohan138/32/1160_2.png) [@Rohan138](https://discuss.ray.io/u/Rohan138)\
**Post date:** [June 29, 2023, 12:51am UTC](https://discuss.ray.io/t/meaning-of-timers-in-rllib-ppo/1652/7 "2023-06-29T00:51:50Z")

</div>

Yes, `mean_env_wait_ms` is basically a timer for `env.send_actions + env.poll`; the former actually calls `env.step`, while the latter just fetches the return values. See [ray/rllib/env/vector\_env.py at master · ray-project/ray · GitHub](https://github.com/ray-project/ray/blob/master/rllib/env/vector_env.py) for more information.
