RE: [PATCH] drm/amdgpu: reduce the full access time by about 50ms

["Zhou, Peng Ju" <PengJu.Zhou@amd.com>]

[AMD Official Use Only - Internal Distribution Only]

Hi Paul
Thanks for you kindly instruction,
I have no hardware spec.


---------------------------------------------------------------------- 
BW
Pengju Zhou




-----Original Message-----
From: Paul Menzel <pmenzel@molgen.mpg.de> 
Sent: Friday, December 25, 2020 6:53 PM
To: Zhou, Peng Ju <PengJu.Zhou@amd.com>
Cc: Deucher, Alexander <Alexander.Deucher@amd.com>; Koenig, Christian <Christian.Koenig@amd.com>; amd-gfx@lists.freedesktop.org
Subject: Re: [PATCH] drm/amdgpu: reduce the full access time by about 50ms

Dear Peng Ju,


For mailing lists, it would be great if you used a mail user agent, which supports quoting (interleaved style), and if you sent plain text messages and no HTML [1].

Am 25.12.20 um 07:34 schrieb Zhou, Peng Ju:

[...]

> 1.  The 50 ms is the whole full access time reduced, not one 
> msleep(1),
> 
> During amdgpu driver init, it will hit msleep(1) several times which increased the total time of full access.

In your logs at the end of your reply, it is a 360 ms difference?

> I load amdgpu in the guest VM and collect VF's full access time in the host, host dmesg  was listed in the below:
> In this time, the time reduced : 0.236847 s - 0.150411 s = 86.436 ms .
> (The reason why it is 80+ms is that I add some code to program one 
> register by psp. )
> 
> VF Start Full access
> VF exit full access
> VF full access time
> msleep(1)
> 295.9031 s
> 296.0535 s
> 0.150411 s
> usleep_range(10, 100)
> 658.1791 s
> 658.4159 s
> 0.236847 s

Is this some output of `time`?

Do you have more details for your hardware?

> 1.  If I only change msleep(1) to usleep_range(10, 100),  the polling 
> time will reduced from 2 seconds to 0.2 seconds,
> 
> So I change timeout from "timeout = 2000;" to "timeout = 20000;"

Sounds good to not change behavior, but I'd be interested where the two seconds comes from.

> host dmesg  with udelay_range(10, 100) in amdgpu:
> 
> [  295.903102] gim info libgv: [4:0:0][amdgv_sched_enter_full_access:877] VF0 entered full access mode.
> [  295.906661] gim info libgv: 
> [4:0:0][amdgv_ih_iv_ring_entry_process:254] PF_VF_MSGBUF_ACK received 
> [  296.052903] gim info libgv: 
> [4:0:0][amdgv_ih_iv_ring_entry_process:192] VF_PF_MSGBUF_VALID 
> received [  296.052910] gim info libgv: 
> [4:0:0][amdgv_ih_iv_ring_entry_process:205] Received Event: VF0, event 
> = 0x2 [  296.052914] gim info libgv: 
> [4:0:0][amdgv_sched_event_queue_push_ex:193] queue event REL_GPU_INIT(0xef01) for VF0 of block(0xf0) [  296.052934] gim info libgv: [4:0:0][amdgv_sched_process_event:1582] process event REL_GPU_INIT (0xef01) for VF0 of block (0xf0) [  296.052944] gim info libgv: [4:0:0][navi12_gpuiov_set_mmsch_vfgate:904] mmsch mb ints disabled schedid = 4 [  296.053334] gim info libgv: [4:0:0][navi12_psp_v11_set_mb_int:632] psp mailbox disabled for VF0 [  296.053513] gim info libgv: [4:0:0][amdgv_sched_exit_full_access:976] VF0 exited full access.
> 
> Host demsg with msleep(1) in amdgpu:
> 
> [  658.179053] gim info libgv: [4:0:0][amdgv_sched_enter_full_access:877] VF0 entered full access mode.
> [  658.182648] gim info libgv: 
> [4:0:0][amdgv_ih_iv_ring_entry_process:254] PF_VF_MSGBUF_ACK received 
> [  658.415227] gim info libgv: 
> [4:0:0][amdgv_ih_iv_ring_entry_process:192] VF_PF_MSGBUF_VALID 
> received [  658.415237] gim info libgv: 
> [4:0:0][amdgv_ih_iv_ring_entry_process:205] Received Event: VF0, event 
> = 0x2 [  658.415241] gim info libgv: 
> [4:0:0][amdgv_sched_event_queue_push_ex:193] queue event REL_GPU_INIT(0xef01) for VF0 of block(0xf0) [  658.415299] gim info libgv: [4:0:0][amdgv_sched_process_event:1582] process event REL_GPU_INIT (0xef01) for VF0 of block (0xf0) [  658.415311] gim info libgv: [4:0:0][navi12_gpuiov_set_mmsch_vfgate:904] mmsch mb ints disabled schedid = 4 [  658.415719] gim info libgv: [4:0:0][navi12_psp_v11_set_mb_int:632] psp mailbox disabled for VF0 [  658.415900] gim info libgv: [4:0:0][amdgv_sched_exit_full_access:976] VF0 exited full access.

I added a DRM_WARN to print out `timeout` value.

> --- a/drivers/gpu/drm/amd/amdgpu/amdgpu_psp.c
> +++ b/drivers/gpu/drm/amd/amdgpu/amdgpu_psp.c
> @@ -285,6 +285,7 @@ psp_cmd_submit_buf(struct psp_context *psp,
>                 usleep_range(10, 100);
>                 amdgpu_asic_invalidate_hdp(psp->adev, NULL);
>         }
> +       DRM_WARN("PSP timeout = %i\n", timeout);
>  
>         /* We allow TEE_ERROR_NOT_SUPPORTED for VMR command and PSP_ERR_UNKNOWN_COMMAND in SRIOV */
>         skip_unsupport = (psp->cmd_buf_mem->resp.status == 
> TEE_ERROR_NOT_SUPPORTED ||

```
$ dmesg | grep timeout
[   57.316303] [drm] PSP timeout = 1993
[   57.319311] [drm] PSP timeout = 1997
[   57.322299] [drm] PSP timeout = 1997
[   57.325297] [drm] PSP timeout = 1997
[   57.328299] [drm] PSP timeout = 1997
[   57.338306] [drm] PSP timeout = 1990
[   57.340363] [drm] PSP timeout = 1998
[   57.350295] [drm] PSP timeout = 1990
[   57.352304] [drm] PSP timeout = 1998
[   57.355306] [drm] PSP timeout = 1997
[   57.362313] [drm] PSP timeout = 1997
[   57.364304] [drm] PSP timeout = 1998
[   57.366382] [drm] PSP timeout = 1998
[   57.376299] [drm] PSP timeout = 1990
[   57.382302] [drm] PSP timeout = 1994
[   57.387311] [drm] PSP timeout = 1996
[   57.390315] [drm] PSP timeout = 1997
[ 3038.312317] [drm] PSP timeout = 1997
[ 3038.314330] [drm] PSP timeout = 1998
[ 3038.316323] [drm] PSP timeout = 1998
[ 3038.325310] [drm] PSP timeout = 1991
[ 3038.960783] [drm] PSP timeout = 1993
[ 3038.963769] [drm] PSP timeout = 1997
[ 3038.966787] [drm] PSP timeout = 1997
[ 3038.969787] [drm] PSP timeout = 1997
[ 3038.972764] [drm] PSP timeout = 1997
[ 3038.981763] [drm] PSP timeout = 1991
[ 3038.983781] [drm] PSP timeout = 1998
[ 3038.993787] [drm] PSP timeout = 1990
[ 3038.995781] [drm] PSP timeout = 1998
[ 3038.998767] [drm] PSP timeout = 1997
[ 3039.001785] [drm] PSP timeout = 1997
[ 3039.004782] [drm] PSP timeout = 1997
[ 3039.007763] [drm] PSP timeout = 1997
[ 3039.018786] [drm] PSP timeout = 1989
[ 3039.023768] [drm] PSP timeout = 1995
[ 3039.026786] [drm] PSP timeout = 1997
[ 3039.029786] [drm] PSP timeout = 1997
[ 3096.984077] [drm] PSP timeout = 1998
[ 3096.985076] [drm] PSP timeout = 1999
[ 3096.988078] [drm] PSP timeout = 1997
[ 3096.997087] [drm] PSP timeout = 1991
[ 3097.638068] [drm] PSP timeout = 1992
[ 3097.642050] [drm] PSP timeout = 1996
[ 3097.646069] [drm] PSP timeout = 1996
[ 3097.649067] [drm] PSP timeout = 1997
[ 3097.652070] [drm] PSP timeout = 1997
[ 3097.661064] [drm] PSP timeout = 1991
[ 3097.663064] [drm] PSP timeout = 1998
[ 3097.672066] [drm] PSP timeout = 1991
[ 3097.674044] [drm] PSP timeout = 1998
[ 3097.676042] [drm] PSP timeout = 1998
[ 3097.678063] [drm] PSP timeout = 1998
[ 3097.681067] [drm] PSP timeout = 1997
[ 3097.684046] [drm] PSP timeout = 1997
[ 3097.695063] [drm] PSP timeout = 1989
[ 3097.700067] [drm] PSP timeout = 1995
[ 3097.704063] [drm] PSP timeout = 1996
[ 3097.707067] [drm] PSP timeout = 1997
[ 3565.319243] [drm] PSP timeout = 1998
[ 3565.320243] [drm] PSP timeout = 1999
[ 3565.322243] [drm] PSP timeout = 1998
[ 3565.331248] [drm] PSP timeout = 1991
[ 3565.900677] [drm] PSP timeout = 1992
[ 3565.904677] [drm] PSP timeout = 1996
[ 3565.907675] [drm] PSP timeout = 1997
[ 3565.910676] [drm] PSP timeout = 1997
[ 3565.913676] [drm] PSP timeout = 1997
[ 3565.922671] [drm] PSP timeout = 1991
[ 3565.924671] [drm] PSP timeout = 1998
[ 3565.934677] [drm] PSP timeout = 1990
[ 3565.936673] [drm] PSP timeout = 1998
[ 3565.939676] [drm] PSP timeout = 1997
[ 3565.942677] [drm] PSP timeout = 1997
[ 3565.945672] [drm] PSP timeout = 1997
[ 3565.948671] [drm] PSP timeout = 1997
[ 3565.959677] [drm] PSP timeout = 1989
[ 3565.964675] [drm] PSP timeout = 1995
[ 3565.967676] [drm] PSP timeout = 1997
[ 3565.970676] [drm] PSP timeout = 1997
[ 4194.378894] [drm] PSP timeout = 1997
[ 4194.380890] [drm] PSP timeout = 1998
[ 4194.383894] [drm] PSP timeout = 1997
[ 4194.392890] [drm] PSP timeout = 1991
[ 4195.054442] [drm] PSP timeout = 1992
[ 4195.057434] [drm] PSP timeout = 1997
[ 4195.060441] [drm] PSP timeout = 1997
[ 4195.063442] [drm] PSP timeout = 1997
[ 4195.066444] [drm] PSP timeout = 1997
[ 4195.075438] [drm] PSP timeout = 1991
[ 4195.077438] [drm] PSP timeout = 1998
[ 4195.087464] [drm] PSP timeout = 1990
[ 4195.089465] [drm] PSP timeout = 1998
[ 4195.092444] [drm] PSP timeout = 1997
[ 4195.095464] [drm] PSP timeout = 1997
[ 4195.098464] [drm] PSP timeout = 1997
[ 4195.101438] [drm] PSP timeout = 1997
[ 4195.112463] [drm] PSP timeout = 1989
[ 4195.117463] [drm] PSP timeout = 1995
[ 4195.120443] [drm] PSP timeout = 1997
[ 4195.123462] [drm] PSP timeout = 1997
```

So, minimum is 1990.

I saw you resent the updated patch. Thank you for that. Please tag those with `v2` (v3, ...).

I'd still extend the commit message with more information. Timing changes are always quite hardware dependent, so a lot of details are necessary.

If you got Reviewed-by tags, you can add them to the iterated patch.


Kind regards,

Paul


[1]: https://nam11.safelinks.protection.outlook.com/?url=https%3A%2F%2Fen.wikipedia.org%2Fwiki%2FPosting_style%23Interleaved_style&amp;data=04%7C01%7CPengJu.Zhou%40amd.com%7C8b8f9a9b252f4a47a60808d8a8c34dd2%7C3dd8961fe4884e608e11a82d994e183d%7C0%7C0%7C637444904111803810%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C1000&amp;sdata=E75h2KWQ%2B6G03oJYxdFk%2FN0mMUv0DUcBv3ULiBWBTu8%3D&amp;reserved=0
[2]: https://nam11.safelinks.protection.outlook.com/?url=https%3A%2F%2Fuseplaintext.email%2F&amp;data=04%7C01%7CPengJu.Zhou%40amd.com%7C8b8f9a9b252f4a47a60808d8a8c34dd2%7C3dd8961fe4884e608e11a82d994e183d%7C0%7C0%7C637444904111803810%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C1000&amp;sdata=L5ZjjzTjfueKGdEPINy1Dz7h62ZsJhTaLgbYuyru1HY%3D&amp;reserved=0
_______________________________________________
amd-gfx mailing list
amd-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/amd-gfx