Bug 107375 - Raven: `amdgpu_device_ip_resume_phase2()` takes 750 ms
Summary: Raven: `amdgpu_device_ip_resume_phase2()` takes 750 ms
Status: RESOLVED MOVED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/AMDgpu (show other bugs)
Version: DRI git
Hardware: Other All
: medium normal
Assignee: Default DRI bug account
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks: 107278
  Show dependency treegraph
 
Reported: 2018-07-25 13:28 UTC by Paul Menzel
Modified: 2019-11-19 08:45 UTC (History)
0 users

See Also:
i915 platform:
i915 features:


Attachments
HTML output of `sudo ./sleepgraph.py -config config/suspend-callgraph.cfg` (devicelist: amdgpu, maxdepth: 12) (1.64 MB, text/html)
2018-07-25 13:28 UTC, Paul Menzel
no flags Details
Do posting read in psp_v10_0_cmd_submit (567 bytes, patch)
2018-07-25 15:10 UTC, Michel Dänzer
no flags Details | Splinter Review

Description Paul Menzel 2018-07-25 13:28:01 UTC
Created attachment 140810 [details]
HTML output of `sudo ./sleepgraph.py -config config/suspend-callgraph.cfg` (devicelist: amdgpu, maxdepth: 12)

Profiling the suspend and resume time [1] on a MSI B350M MORTAR (MS-7A37) with AMD Ryzen 3 2200G with Radeon Vega Graphics with Linux 4.18-rc6+ and amd-staging-drm-next [2], `pci_pm_suspend()` takes over one second, which is too long [3], cf. bug 107278 [3].

The majority of that, 750 ms, is spent in `amdgpu_device_ip_resume_phase2()`.

•   amdgpu_device_ip_resume_phase2 [amdgpu] (747.134 ms @ 97.889371)
    •   psp_resume [amdgpu] (673.370 ms @ 97.889371)
        […]
        •   psp_hw_start [amdgpu] (88.577 ms @ 97.889379)
        […]
        •   psp_np_fw_load [amdgpu] (584.783 ms @ 97.977957)
    […]
    •   dm_resume [amdgpu] (44.992 ms @ 98.567232)
        […]
        •   dc_link_detect [amdgpu] (17.777 ms @ 98.568212)
            (EDID read takes 8 ms?)
        […]
        •   drm_atomic_helper_resume (25.139 ms @ 98.587030)
        […]
    […]

In the PSP code the problem is `psp_cmd_submit_buf()`, which takes from 45 ms to 141 ms. Something is wrong there.

```
static int
psp_cmd_submit_buf(struct psp_context *psp,
                   struct amdgpu_firmware_info *ucode,
                   struct psp_gfx_cmd_resp *cmd, uint64_t fence_mc_addr,
                   int index)
{
        int ret;

        memset(psp->cmd_buf_mem, 0, PSP_CMD_BUFFER_SIZE);

        memcpy(psp->cmd_buf_mem, cmd, sizeof(struct psp_gfx_cmd_resp));

        ret = psp_cmd_submit(psp, ucode, psp->cmd_buf_mc_addr,
                             fence_mc_addr, index);

        while (*((unsigned int *)psp->fence_buf) != index) {
                msleep(1);
        }

        return ret;
}
```

Also, I wonder why the sleep in the trace is 3 ms instead of 1 ms like in the code.


[1]: https://01.org/suspendresume
[2]: https://cgit.freedesktop.org/~agd5f/linux/log/?h=amd-staging-drm-next
[3]: https://bugs.freedesktop.org/show_bug.cgi?id=107278
Comment 1 Michel Dänzer 2018-07-25 15:10:01 UTC
Created attachment 140814 [details] [review]
Do posting read in psp_v10_0_cmd_submit

Does this patch help by any chance?

(In reply to Paul Menzel from comment #0)
> Also, I wonder why the sleep in the trace is 3 ms instead of 1 ms like in
> the code.

Maybe your kernel is configured with CONFIG_HZ=300? Anyway, it doesn't really matter, as it's waiting for the PSP to finish processing the command.
Comment 2 Paul Menzel 2018-07-25 15:54:50 UTC
(In reply to Michel Dänzer from comment #1)
> Created attachment 140814 [details] [review] [review]
> Do posting read in psp_v10_0_cmd_submit
> 
> Does this patch help by any chance?

No, unfortunately it does not change the times.

> (In reply to Paul Menzel from comment #0)
> > Also, I wonder why the sleep in the trace is 3 ms instead of 1 ms like in
> > the code.
> 
> Maybe your kernel is configured with CONFIG_HZ=300? Anyway, it doesn't
> really matter, as it's waiting for the PSP to finish processing the command.

```
$ grep CONFIG_HZ .config
# CONFIG_HZ_PERIODIC is not set
# CONFIG_HZ_100 is not set
# CONFIG_HZ_250 is not set
# CONFIG_HZ_300 is not set
CONFIG_HZ_1000=y
CONFIG_HZ=1000
```
Comment 3 Paul Menzel 2018-09-17 15:37:58 UTC
With v4.19-rc4-22-gad3273d5f1b9 (Merge tag 'ext4_for_linus_stable' of git://git.kernel.org/pub/scm/linux/kernel/git/tytso/ext4) this now got worse, and `amdgpu_device_ip_resume_phase2()` now takes 1.166 s.

`psp_np_fw_load()` takes 868.190 ms, and `dm_resume()` 178.380 ms.

It’d be great, if you could talk to the PSP firmware team, and also document, if you can reproduce this.
Comment 4 Martin Peres 2019-11-19 08:45:17 UTC
-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/drm/amd/issues/462.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.