Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

on heap allocations done by the background compiler incur unpredictable pauses #32904

Open
mraleph opened this issue Apr 17, 2018 · 3 comments
Open

on heap allocations done by the background compiler incur unpredictable pauses #32904

mraleph opened this issue Apr 17, 2018 · 3 comments
Assignees
@mraleph
Labels
area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends.

Comments

@mraleph
Copy link
Member

mraleph commented Apr 17, 2018 •
edited
Loading

In 5909932 I have replaced on Double::NewCanonical with Double::New(..., Heap::kOld) in the compiler.

This caused completely unexpected timeouts on Flutter tests internally. I added some time measurement around Double::New(..., Heap::kOld) and printed verbose timings for GC.

Here is what I got:

Shell: [              |                      |     |       |      | new gen     | new gen     | new gen | old gen       | old gen       | old gen     | sweep | safe- | roots/| stbuf/| tospc/| weaks/|               ]
Shell: [ GC isolate   | space (reason)       | GC# | start | time | used (kB)   | capacity kB | external| used (kB)     | capacity (kB) | external kB | thread| point |marking| reset | sweep |swplrge| data          ]
Shell: [              |                      |     |  (s)  | (ms) |before| after|before| after| b4 |aftr| before| after | before| after |before| after| (ms)  | (ms)  | (ms)  | (ms)  | (ms)  | (ms)  |               ]
Shell: [ tests_test_ui,   Scavenge(     full),    1,   0.51,   1.9,  1148,     0,  2048,  2048,   0,   0,  45707,  45921,  45912,  46168,     0,     0,   0.00,   0.00,   0.10,   1.12,   0.20,   0.00, 1579, 0, 0, 0, ]
Shell: [ tests_test_ui, Mark-Sweep(     full),    2,   0.52,  10.2,     0,     0,  2048,  2048,   0,   0,  45921,  42038,  46168,  45900,     0,     0,   0.00,   0.00,   9.94,   0.00,   0.21,   0.01, 10, 0, 280, 280, ]
Shell: [ tests_test_ui,   Scavenge(new space),    3,   0.93,   1.7,  1269,   168,  2048,  8192,  66,  64,  53188,  53188,  53652,  53652,     0,     0,   0.00,   0.00,   0.10,   0.41,   0.30,   0.01, 623, 0, 0, 121, ]
Shell: [ tests_test_ui,   Scavenge(new space),    4,   1.63,   4.9,   676,   666,  8192,  8192, 147,  82,  77026,  77159,  77716,  77972,     0,    64,   0.00,   0.00,   1.22,   0.82,   1.92,   0.02, 1396, 0, 0, 260, ]
Shell: [ tests_test_ui,   Scavenge(new space),    5,   1.75,   2.0,   666,    13,  8192,  8192,  84,   2,  77513,  78173,  78484,  78740,    64,   146,   0.00,   0.00,   0.10,   0.40,   1.08,   0.01, 913, 0, 0, 10, ]
Shell: [ tests_test_ui,   Scavenge(new space),    6,   1.88,   0.7,    13,     0,  8192,  8192,   2,   0,  78507,  78523,  79252,  79252,   146,   148,   0.00,   0.00,   0.12,   0.08,   0.02,   0.01, 84, 0, 0, 0, ]
Shell: Canonicalizing 0.0
Shell: ... done canonicalizing in 0 ms.
Shell: Canonicalizing 0.0
Shell: ... done canonicalizing in 0 ms.
Shell: [ tests_test_ui,   Scavenge(new space),    7,   2.13,   2.6,  2449,   471,  8192,  8192,  41,  32,  82452,  82452,  83092,  83092,   148,   148,   0.00,   0.01,   0.23,   0.25,   1.33,   0.07, 289, 0, 0, 86, ]
Shell: [ tests_test_ui,   Scavenge(new space),    8,   2.28,   2.1,   471,     5,  8192,  8192,  32,   0,  82466,  82934,  83092,  83604,   148,   181,   0.00,   0.00,   0.14,   0.21,   1.25,   0.01, 263, 0, 0, 4, ]
Shell: [ tests_test_ui,   Scavenge(new space),    9,   2.52,   1.3,     5,     0,  8192,  8192,  16,   0,  89278,  89448,  90008,  90008,   181,   196,   0.00,   0.00,   0.14,   0.34,   0.29,   0.02, 405, 0, 0, 0, ]
Shell: [ tests_test_ui,   Scavenge(new space),   10,   2.73,   1.1,     0,   118,  8192,  8192,  42,  30,  91185,  91185,  91800,  91800,   196,   196,   0.00,   0.04,   0.14,   0.23,   0.19,   0.04, 384, 0, 0, 76, ]
Shell: [ tests_test_ui,   Scavenge(new space),   11,   4.19, 1344.7,   118,    23,  8192,  8192,  56,  15,  91905, 117107,  92312, 117656,   196,   214,   0.00, 1198.88, 144.92,   0.24,   0.15,   0.04, 384, 0, 0, 14, ]
Shell: [ tests_test_ui, Mark-Sweep(promotion),   12,   4.36, 171.2,    23,    23,  8192,  8192,  15,  15, 117107,  94245, 117656, 116880,   214,   164,   0.00,   0.00, 169.48,   0.00,   1.70,   0.01, 30, 4, 280, 280, ]
Shell: [ tests_test_ui,   Scavenge(     full),   13,   4.50, 144.6,    23,     0,  8192,  8192,  15,   0,  94245,  94269, 116880, 117136,   164,   180,   0.00,   0.00, 143.87,   0.14,   0.07,   0.01, 123, 0, 0, 0, ]
Shell: [ tests_test_ui, Mark-Sweep(     full),   14,   4.77, 264.0,     0,  2945,  8192,  8192,   0,  16,  94269,  94255, 117136, 117136,   180,   164,  46.70,   0.00, 215.96,   0.00,   1.35,   0.01, 65, 9, 151, 151, ]
Shell: [background] VisitBinaryDoubleOp allocation took 725 ms.
Shell: [ tests_test_ui,   Scavenge(new space),   15,   8.31, 3475.8,  2945,     0,  8192,  8192,  47,   0,  95578, 155265, 117136, 156048,   164,   180,   0.00, 2974.71, 500.22,   0.17,   0.05,   0.07, 171, 0, 0, 0, ]
Shell: [ tests_test_ui, Mark-Sweep(promotion),   16,   9.08, 775.5,     0,     0,  8192,  8192,   0,   0, 155265, 155091, 156048, 156048,   180,   180,   0.00,   0.00, 774.11,   0.00,   1.37,   0.01, 0, 13, 280, 280, ]
Shell: [ tests_test_ui,   Scavenge(     full),   17,   9.59, 505.1,     0,     0,  8192,  8192,   0,   0, 155091, 155091, 156048, 156048,   180,   180,   0.00,   0.00, 504.47,   0.05,   0.00,   0.01, 1, 0, 0, 0, ]
Shell: [ tests_test_ui, Mark-Sweep(     full),   18,  10.49, 897.2,     0,  5513,  8192,  8192,   0,  25, 155091, 155071, 156048, 156304,   180,   177, 117.79,   0.00, 778.05,   0.00,   1.33,   0.01, 100, 28, 280, 280, ]
Shell: [background] VisitBinaryDoubleOp allocation took 2679 ms.
Shell: [ tests_test_ui,   Scavenge(new space),   19,  15.14, 4623.0,  5513,     0,  8192,  8192,  25,   0, 155852, 227291, 157072, 228496,   177,   197,   0.00, 3636.94, 984.32,   0.10,   1.17,   0.05, 57, 0, 0, 0, ]
Shell: [ tests_test_ui, Mark-Sweep(promotion),   20,  16.95, 1809.9,     0,     0,  8192,  8192,   0,   0, 227291, 226932, 228496, 228496,   197,   148,  70.53,   0.00, 1737.99,   0.00,   1.36,   0.01, 0, 27, 280, 280, ]
Shell: [ tests_test_ui,   Scavenge(new space),   21,  18.09, 1019.8,     0,     6,  8192,  8192,   0,   0, 226932, 226932, 228496, 228496,   148,   148,   0.00,   0.28, 1019.00,   0.05,   0.01,   0.01, 20, 0, 0, 6, ]
Shell: [background] VisitBinaryDoubleOp allocation took 4005 ms.
Shell: [ tests_test_ui,   Scavenge(new space),   22,  23.80, 5588.1,     6,    92,  8192,  8192,  30,  18, 228433, 299664, 229008, 300432,   148,   148,   0.00, 4030.31, 1556.66,   0.32,   0.18,   0.04, 435, 0, 0, 44, ]
Shell: [ tests_test_ui, Mark-Sweep(promotion),   23,  26.20, 2400.1,    92,    92,  8192,  8192,  18,  18, 299664, 299231, 300432, 300432,   148,   144,   0.00,   0.00, 2398.76,   0.00,   1.37,   0.01, 0, 28, 293, 293, ]
Shell: [ tests_test_ui,   Scavenge(     full),   24,  27.66, 1463.8,    92,     0,  8192,  8192,  18,   0, 299231, 299322, 300432, 300688,   144,   162,   0.00,   0.00, 1462.68,   0.26,   0.23,   0.01, 414, 0, 0, 0, ]
Shell: [ tests_test_ui, Mark-Sweep(     full),   25,  30.21, 2540.4,     0,  8192,  8192,  8192,   0,  42, 299322, 299330, 300688, 300688,   162,   149, 280.53,   0.00, 2258.52,   0.01,   1.34,   0.01, 21, 32, 293, 293, ]
Shell: [background] VisitBinaryDoubleOp allocation took 7963 ms.
Shell: [ tests_test_ui,   Scavenge(new space),   26,  36.41, 6200.8,  8192,     0,  8192,  8192,  42,   0, 299330, 374332, 300688, 375952,   149,   162,   0.00, 4251.45, 1948.58,   0.11,   0.04,   0.05, 78, 0, 0, 0, ]
Shell: [ tests_test_ui, Mark-Sweep(promotion),   27,  39.43, 3020.2,     0,     0,  8192,  8192,   0,   0, 374332, 373050, 375952, 375952,   162,   162, 278.78,   0.00, 2739.05,   0.00,   2.38,   0.02, 1, 32, 367, 367, ]
Shell: [ tests_test_ui,   Scavenge(new space),   28,  41.28, 1643.2,  4362,   393,  8192,  8192,  48,  29, 373939, 373939, 376208, 376208,   162,   162,   0.00,   0.10, 1641.38,   0.13,   0.78,   0.07, 127, 0, 0, 26, ]
Shell: [ tests_test_ui,   Scavenge(new space),   29,  43.22, 1851.3,   393,     7,  8192,  8192,  31,   2, 373939, 374329, 376208, 376208,   162,   191,   0.00,   0.13, 1849.49,   0.10,   1.02,   0.02, 105, 0, 0, 4, ]

These timings are very concerning: there are moments where VM takes 3 seconds to safepoint for GC and root marking times are measured in seconds.

/cc @a-siva @ErikCorryGoogle @rmacnak-google @mkustermann
@mraleph mraleph added the area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends. label Apr 17, 2018
@mraleph mraleph self-assigned this Apr 17, 2018
@mraleph mraleph mentioned this issue Apr 17, 2018
Open
@rmacnak-google
Copy link
Contributor

What command are you running?

dart-bot pushed a commit that referenced this issue Apr 20, 2018
@mraleph
[vm/compiler] Canonicalize more intermediate constants in IL.
375b32d 
* when building IL from Kernel use canonical double representation
instead of allocating new double objects;
* in constant propagation canonicalize immutable primitive constants
(strings, mints and doubles) before replacing instruction with its
constant value;

This relands 5909932 with the part
that was causing timeouts on flutter_test reverted.

See #32904 for more details.

TBR=aam@google.com

Change-Id: I0c128e44dd6c9689c4b7e9dd91832408214847f3
Reviewed-on: https://dart-review.googlesource.com/51460
Reviewed-by: Vyacheslav Egorov <vegorov@google.com>
Reviewed-by: Alexander Aprelev <aam@google.com>
Commit-Queue: Vyacheslav Egorov <vegorov@google.com>
@mkustermann
Copy link
Member

@mraleph Was this issue fixed?

@mraleph
Copy link
Member Author

mraleph commented May 8, 2018

I worked around the slow down I was seeing. I think the real issue is still there.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mraleph mraleph

Labels
area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@mraleph @mkustermann @rmacnak-google