You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@flink.apache.org by "Matthias Pohl (Jira)" <ji...@apache.org> on 2022/04/11 06:38:00 UTC

[jira] [Comment Edited] (FLINK-27133) Performance regression in serializerHeavyString

    [ https://issues.apache.org/jira/browse/FLINK-27133?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17520327#comment-17520327 ] 

Matthias Pohl edited comment on FLINK-27133 at 4/11/22 6:37 AM:
----------------------------------------------------------------

I focused on the following commits in my more recent analysis:
 * caa296b8 (\{{checkOpen}} invariant added in \{{LocalDataOutputStream}})
 * c50b0706 (removing {{flush}} from \{{FileSystemJobResultStore.createDirtyJobResultEntry}})
 * 26aa543b (DelegationTokenManager change)

* Build [#91|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/91/console], [#93|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/93/console], [#94|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/94/console]: caa296b8 (base) with 26aa543b being reverted
{code}
20:47:36    219.976 ±(99.9%) 15.001 ops/ms [Average]
20:47:36    (min, avg, max) = (199.255, 219.976, 254.392), stdev = 22.453
20:47:36    CI (99.9%): [204.975, 234.978] (assumes normal distribution)

15:37:21    219.255 ±(99.9%) 13.850 ops/ms [Average]
15:37:21    (min, avg, max) = (199.040, 219.255, 250.275), stdev = 20.730
15:37:21    CI (99.9%): [205.405, 233.105] (assumes normal distribution)

15:57:17    234.844 ±(99.9%) 14.785 ops/ms [Average]
15:57:17    (min, avg, max) = (200.617, 234.844, 253.508), stdev = 22.130
15:57:17    CI (99.9%): [220.059, 249.630] (assumes normal distribution)
{code}
* Build [#95|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/95/console], [#96|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/96/console], [#97|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/97/console]: Like #91 + caa296b8 being reverted
{code}
16:12:25    235.476 ±(99.9%) 14.475 ops/ms [Average]
16:12:25    (min, avg, max) = (203.669, 235.476, 254.322), stdev = 21.666
16:12:25    CI (99.9%): [221.001, 249.952] (assumes normal distribution)

16:27:27    235.626 ±(99.9%) 15.342 ops/ms [Average]
16:27:27    (min, avg, max) = (201.173, 235.626, 255.049), stdev = 22.963
16:27:27    CI (99.9%): [220.284, 250.967] (assumes normal distribution)

16:42:29    234.462 ±(99.9%) 15.133 ops/ms [Average]
16:42:29    (min, avg, max) = (199.156, 234.462, 253.515), stdev = 22.651
16:42:29    CI (99.9%): [219.328, 249.595] (assumes normal distribution)
{code}
* Build [#98|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/98/console], [#99|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/99/console], [#100|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/100/console]: Like #95 + c50b0706 being reverted
{code}
17:13:58    235.310 ±(99.9%) 14.886 ops/ms [Average]
17:13:58    (min, avg, max) = (202.351, 235.310, 254.051), stdev = 22.280
17:13:58    CI (99.9%): [220.424, 250.196] (assumes normal distribution)

17:29:06    219.856 ±(99.9%) 14.974 ops/ms [Average]
17:29:06    (min, avg, max) = (200.351, 219.856, 253.669), stdev = 22.413
17:29:06    CI (99.9%): [204.882, 234.830] (assumes normal distribution)

17:44:09    219.721 ±(99.9%) 14.996 ops/ms [Average]
17:44:09    (min, avg, max) = (196.237, 219.721, 253.804), stdev = 22.445
17:44:09    CI (99.9%): [204.725, 234.716] (assumes normal distribution)
{code}
* Build [#101|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/101/console], [#102|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/102/console], [#103|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/103/console]: Reset to cda343349f (pre Delegation Token Manager change; parent of 26aa543b)
{code}
18:29:35    235.985 ±(99.9%) 15.012 ops/ms [Average]
18:29:35    (min, avg, max) = (203.411, 235.985, 257.348), stdev = 22.469
18:29:35    CI (99.9%): [220.973, 250.996] (assumes normal distribution)

18:44:46    219.430 ±(99.9%) 15.044 ops/ms [Average]
18:44:46    (min, avg, max) = (192.279, 219.430, 252.936), stdev = 22.517
18:44:46    CI (99.9%): [204.386, 234.474] (assumes normal distribution)

18:59:43    253.396 ±(99.9%) 1.829 ops/ms [Average]
18:59:43    (min, avg, max) = (246.030, 253.396, 256.858), stdev = 2.737
18:59:43    CI (99.9%): [251.567, 255.225] (assumes normal distribution)
{code}
* Build [#104|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/104/console], [#105|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/105/console], [#106|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/106/console]: Like #101 with caa296b8 being added
{code}
19:42:59    249.811 ±(99.9%) 2.284 ops/ms [Average]
19:42:59    (min, avg, max) = (238.872, 249.811, 254.049), stdev = 3.418
19:42:59    CI (99.9%): [247.527, 252.095] (assumes normal distribution)

20:03:25    220.641 ±(99.9%) 15.517 ops/ms [Average]
20:03:25    (min, avg, max) = (199.993, 220.641, 255.706), stdev = 23.226
20:03:25    CI (99.9%): [205.123, 236.158] (assumes normal distribution)

20:18:30    220.226 ±(99.9%) 15.102 ops/ms [Average]
20:18:30    (min, avg, max) = (200.096, 220.226, 254.146), stdev = 22.604
20:18:30    CI (99.9%): [205.124, 235.328] (assumes normal distribution)
{code}


was (Author: mapohl):
I focused on the following commits in my more recent analysis:
 * caa296b8 (\{{checkOpen}} invariant added in \{{LocalDataOutputStream}})
 * c50b0706 (removing {{flush}} from \{{FileSystemJobResultStore.createDirtyJobResultEntry}})
 * 26aa543b (DelegationTokenManager change)

* Build [#91|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/91/console], [#93|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/93/console], [#94|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/94/console]: caa296b8 (base) with 26aa543b being reverted
{code}
20:47:36    219.976 ±(99.9%) 15.001 ops/ms [Average]
20:47:36    (min, avg, max) = (199.255, 219.976, 254.392), stdev = 22.453
20:47:36    CI (99.9%): [204.975, 234.978] (assumes normal distribution)

15:37:21    219.255 ±(99.9%) 13.850 ops/ms [Average]
15:37:21    (min, avg, max) = (199.040, 219.255, 250.275), stdev = 20.730
15:37:21    CI (99.9%): [205.405, 233.105] (assumes normal distribution)

15:57:17    234.844 ±(99.9%) 14.785 ops/ms [Average]
15:57:17    (min, avg, max) = (200.617, 234.844, 253.508), stdev = 22.130
15:57:17    CI (99.9%): [220.059, 249.630] (assumes normal distribution)
{code}
* Build [#95|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/95/console], [#96|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/96/console], [#97|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/97/console]: Like #91 + caa296b8 being reverted
{code}
16:12:25    235.476 ±(99.9%) 14.475 ops/ms [Average]
16:12:25    (min, avg, max) = (203.669, 235.476, 254.322), stdev = 21.666
16:12:25    CI (99.9%): [221.001, 249.952] (assumes normal distribution)

16:27:27    235.626 ±(99.9%) 15.342 ops/ms [Average]
16:27:27    (min, avg, max) = (201.173, 235.626, 255.049), stdev = 22.963
16:27:27    CI (99.9%): [220.284, 250.967] (assumes normal distribution)

16:42:29    234.462 ±(99.9%) 15.133 ops/ms [Average]
16:42:29    (min, avg, max) = (199.156, 234.462, 253.515), stdev = 22.651
16:42:29    CI (99.9%): [219.328, 249.595] (assumes normal distribution)
{code}
* Build [#98|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/98/console], [#99|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/99/console], [#100|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/100/console]: Like #95 + c50b0706 being reverted
{code}
17:13:58    235.310 ±(99.9%) 14.886 ops/ms [Average]
17:13:58    (min, avg, max) = (202.351, 235.310, 254.051), stdev = 22.280
17:13:58    CI (99.9%): [220.424, 250.196] (assumes normal distribution)

17:29:06    219.856 ±(99.9%) 14.974 ops/ms [Average]
17:29:06    (min, avg, max) = (200.351, 219.856, 253.669), stdev = 22.413
17:29:06    CI (99.9%): [204.882, 234.830] (assumes normal distribution)

17:44:09    219.721 ±(99.9%) 14.996 ops/ms [Average]
17:44:09    (min, avg, max) = (196.237, 219.721, 253.804), stdev = 22.445
17:44:09    CI (99.9%): [204.725, 234.716] (assumes normal distribution)
{code}
* Build [#101|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/101/console], [#102|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/102/console], [#103|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/103/console]: Reset to cda343349f (pre Delegation Token Manager change; parent of 26aa543b)
{code}
18:29:35    235.985 ±(99.9%) 15.012 ops/ms [Average]
18:29:35    (min, avg, max) = (203.411, 235.985, 257.348), stdev = 22.469
18:29:35    CI (99.9%): [220.973, 250.996] (assumes normal distribution)

18:44:46    219.430 ±(99.9%) 15.044 ops/ms [Average]
18:44:46    (min, avg, max) = (192.279, 219.430, 252.936), stdev = 22.517
18:44:46    CI (99.9%): [204.386, 234.474] (assumes normal distribution)

18:59:43    253.396 ±(99.9%) 1.829 ops/ms [Average]
18:59:43    (min, avg, max) = (246.030, 253.396, 256.858), stdev = 2.737
18:59:43    CI (99.9%): [251.567, 255.225] (assumes normal distribution)
{code}
* Build [#104|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/104/console], [#105|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/105/console], [#106|http://codespeed.dak8s.net:8080/job/flink-benchmark-request/106/console]: Like #101 with caa296b8 being reverted
{code}
19:42:59    249.811 ±(99.9%) 2.284 ops/ms [Average]
19:42:59    (min, avg, max) = (238.872, 249.811, 254.049), stdev = 3.418
19:42:59    CI (99.9%): [247.527, 252.095] (assumes normal distribution)

20:03:25    220.641 ±(99.9%) 15.517 ops/ms [Average]
20:03:25    (min, avg, max) = (199.993, 220.641, 255.706), stdev = 23.226
20:03:25    CI (99.9%): [205.123, 236.158] (assumes normal distribution)

20:18:30    220.226 ±(99.9%) 15.102 ops/ms [Average]
20:18:30    (min, avg, max) = (200.096, 220.226, 254.146), stdev = 22.604
20:18:30    CI (99.9%): [205.124, 235.328] (assumes normal distribution)
{code}

> Performance regression in serializerHeavyString
> -----------------------------------------------
>
>                 Key: FLINK-27133
>                 URL: https://issues.apache.org/jira/browse/FLINK-27133
>             Project: Flink
>          Issue Type: Bug
>          Components: API / Type Serialization System, Benchmarks
>    Affects Versions: 1.15.0, 1.16.0
>            Reporter: Piotr Nowojski
>            Assignee: Matthias Pohl
>            Priority: Blocker
>             Fix For: 1.15.0, 1.16.0
>
>
> http://codespeed.dak8s.net:8000/timeline/#/?exe=1&ben=serializerHeavyString&extr=on&quarts=on&equid=off&env=2&revs=200
> Suspected range: 5f21d15a09..caa296b813
> {noformat}
> caa296b813b [8 days ago] [FLINK-26957][runtime] Adds invariant to LocalDataOutputStream to verify that no operation is allowed on a closed stream [Matthias Pohl]
> c50b0706237 [8 days ago] [FLINK-26957][runtime] Removes flush in FileSystemJobResultStore [Matthias Pohl]
> 098dc7eca31 [7 days ago] [hotfix] Fixes error in JavaDoc [Matthias Pohl]
> 116f297478f [7 days ago] [hotfix] Fixes typo in NonClosingOutputStreamDecorator [Matthias Pohl]
> 74ecbd13cf8 [7 days ago] [hotfix][runtime] Adds write method for consistency reasons [Matthias Pohl]
> e031f82528b [5 days ago] [hotfix] Modify spelling error in IOUtils.java [lidefu]
> a5a31de5b30 [4 days ago] [FLINK-26368] [kafka] Add setProperty method to KafkaSinkBuilder [Gyula Fora]
> b9c874edae8 [4 days ago] [hotfix][metrics][docs] Update documentation [Chesnay Schepler]
> 3416b6440ac [6 days ago] [FLINK-27027][ci] Add default log file suffix [Chesnay Schepler]
> 0d105ac910d [6 days ago] [FLINK-27027][ci] Prevent creation of empty log files [Chesnay Schepler]
> 7ad47230f22 [4 days ago] [FLINK-27026][build] Upgrade checkstyle plugin [Chesnay Schepler]
> db8522cfddb [4 days ago] [FLINK-27034][gcp][tests] Use testcontainers [Chesnay Schepler]
> 0097b5a6fae [3 weeks ago] [FLINK-26712][table-planner] Metadata keys should not conflict with physical columns [Timo Walther]
> 26aa543b3bb [3 months ago] [FLINK-25907][runtime][security] Add pluggable delegation token manager [gabor.g.somogyi]
> cda343349f5 [7 days ago] [FLINK-26987][runtime] Fixes getAllAndLock livelock [Matthias Pohl]
> {noformat}
> I've run a benchmark request before FLINK-26957 and it suggests that it is indeed the cause for this regression:
> http://codespeed.dak8s.net:8080/job/flink-benchmark-request/77/artifact/jmh-result.csv/*view*/
> CC [~mapohl]



--
This message was sent by Atlassian Jira
(v8.20.1#820001)