graalvm / sulong

Obsolete repository. Moved to oracle/graal.
Other
628 stars 63 forks source link

Permanent optimization/deoptimization of functions causes huge program slowdown #824

Closed pointhi closed 6 years ago

pointhi commented 6 years ago

How to Reproduce

(you need wllvm installed)

git clone https://github.com/wbhart/bsdnt
cd bsdnt
BSDNT_DIR=`pwd` # for later
./configure
export LLVM_COMPILER=clang
make AS='wllvm' CC='wllvm'
extract-bc build/test/t-nn
# in sulong dir:
mx --jdk jvmci --dynamicimports=/compiler lli "$BSDNT_DIR/build/test/t-nn.bc" -Dgraal.TraceTruffleCompilation=true -Dgraal.TraceTruffleCompilation=true

Example output

It can be seen, there is a continues flow of optimizations and deoptimizations slowing down the program by a big amount. It's expected that a more generic version of compiled code is used after some time to prevent continuous optimization and deoptimization of running code.

$ mx --jdk jvmci --dynamicimports=/compiler lli "$BSDNT_DIR/build/test/t-nn.bc" -Dgraal.TraceTruffleCompilation=true -Dgraal.TraceTruffleCompilation=true

Testing nn functions:
First Random Word: 7bf856948de350b4
[truffle] opt done         @kiss_word <opt>                                            |ASTSize     177/  177 |Time   510( 342+168 )ms |DirectCallNodes I    0/D    0 |GraalNodes   149/  170 |CodeSize          498 |CodeAddress 0x7f36eda7de10 |Source     kiss.c:104 
mul_m...[truffle] opt done         @nn_addmul1_c <opt>                                         |ASTSize     337/  337 |Time   923( 538+385 )ms |DirectCallNodes I    0/D    0 |GraalNodes  1226/ 2757 |CodeSize        12005 |CodeAddress 0x7f36edc78fd0 |Source nn_linear.c:384 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   462( 371+91  )ms |DirectCallNodes I    4/D    1 |GraalNodes   801/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_add_mc <opt>                                            |ASTSize     339/  339 |Time   420( 212+208 )ms |DirectCallNodes I    0/D    0 |GraalNodes  1098/ 2502 |CodeSize        10848 |CodeAddress 0x7f36ede77b10 |Source nn_linear.c:205 
[truffle] opt done         @nn_sub_mc <opt>                                            |ASTSize     296/  296 |Time   317( 179+138 )ms |DirectCallNodes I    0/D    0 |GraalNodes   809/ 2073 |CodeSize         8340 |CodeAddress 0x7f36edfe4750 |Source nn_linear.c:226 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    86(  75+11  )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee04d950 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      21/   24 |CallsAndLoop/Thres    8797/ 8751 |Inval#              1 
[truffle] opt done         @nn_mul_classical <opt>                                     |ASTSize     154/  783 |Time   891( 438+453 )ms |DirectCallNodes I    2/D    0 |GraalNodes  2315/ 6242 |CodeSize        26688 |CodeAddress 0x7f36ee0cbf10 |Source nn_quadratic.c:36 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   224( 191+33  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2405 |CodeAddress 0x7f36ee14d510 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    75(  66+9   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee179ed0 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      24/   27 |CallsAndLoop/Thres   11284/10918 |Inval#              2 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres      64/   67 |CallsAndLoop/Thres    8143/ 7696 |Inval#              1 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    62(  54+9   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed6e8fd0 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      30/   33 |CallsAndLoop/Thres   12346/11925 |Inval#              3 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   200( 165+35  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2405 |CodeAddress 0x7f36ed258350 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres      84/   87 |CallsAndLoop/Thres    9882/ 9664 |Inval#              2 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    77(  67+10  )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed5fe310 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      33/   36 |CallsAndLoop/Thres   15131/14876 |Inval#              4 
[truffle] opt done         @nn_add1 <opt>                                              |ASTSize     460/  460 |Time   150( 118+31  )ms |DirectCallNodes I    0/D    0 |GraalNodes   553/  716 |CodeSize         2117 |CodeAddress 0x7f36ed5b4010 |Source nn_linear.c:293 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   179( 147+32  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2405 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    54(  46+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed777110 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      39/   42 |CallsAndLoop/Thres   16278/16237 |Inval#              5 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   177( 146+30  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    68(  57+12  )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed8a3710 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      42/   45 |CallsAndLoop/Thres   18058/17752 |Inval#              6 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   160( 131+29  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ed7bebd0 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     134/  137 |CallsAndLoop/Thres   16452/16448 |Inval#              3 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    52(  45+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed7f33d0 |Source nn_linear.c:59 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   149( 114+35  )ms |DirectCallNodes I    4/D    1 |GraalNodes   801/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_mul_m <opt>                                             |ASTSize      95/   95 |Time    63(  41+23  )ms |DirectCallNodes I    0/D    2 |GraalNodes   154/  797 |CodeSize         3226 |CodeAddress 0x7f36ed13c050 |Source        nn.c:31 
[truffle] opt done         @nn_sub1 <opt>                                              |ASTSize     399/  399 |Time    81(  62+18  )ms |DirectCallNodes I    0/D    0 |GraalNodes   516/  704 |CodeSize         2229 |CodeAddress 0x7f36ed43ccd0 |Source nn_linear.c:316 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      46/   49 |CallsAndLoop/Thres   21474/20660 |Inval#              7 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   160( 130+30  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt invalidated  @nn_test_random2                                            |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random2                                            |ASTSize     705/ 1413 |Time    55(  46+9   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress       0x0 |Source nn_linear.c:59 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    56(  47+9   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee14efd0 |Source nn_linear.c:59 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   214( 176+38  )ms |DirectCallNodes I    4/D    1 |GraalNodes  1199/ 1030 |CodeSize         2992 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      61/   64 |CallsAndLoop/Thres   25078/24879 |Inval#              8 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   152( 121+31  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    58(  47+12  )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed930cd0 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      67/   70 |CallsAndLoop/Thres   28171/27660 |Inval#              9 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   146( 119+27  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36edec3590 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     197/  200 |CallsAndLoop/Thres   22545/22485 |Inval#              5 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    47(  40+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed895a50 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      70/   73 |CallsAndLoop/Thres   29853/29466 |Inval#             10 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   159( 132+27  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ed8fb310 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     207/  210 |CallsAndLoop/Thres   23517/23402 |Inval#              6 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    43(  34+9   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed95f690 |Source nn_linear.c:59 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   124( 105+19  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ee288c50 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     211/  214 |CallsAndLoop/Thres   23860/23863 |Inval#              7 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      75/   78 |CallsAndLoop/Thres   32173/32084 |Inval#             11 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   144( 114+30  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ee3237d0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    56(  46+11  )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee365150 |Source nn_linear.c:59 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     229/  232 |CallsAndLoop/Thres   25397/25243 |Inval#              8 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      79/   82 |CallsAndLoop/Thres   34634/34375 |Inval#             12 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    47(  40+7   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed7f33d0 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      82/   85 |CallsAndLoop/Thres   35679/35676 |Inval#             13 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   166( 130+36  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    41(  35+6   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed131c50 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      85/   88 |CallsAndLoop/Thres   37072/36173 |Inval#             14 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   139( 113+26  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ee39f310 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     260/  263 |CallsAndLoop/Thres   28913/28909 |Inval#              9 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    50(  42+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee3be950 |Source nn_linear.c:59 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   152( 124+28  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      88/   91 |CallsAndLoop/Thres   38428/38267 |Inval#             15 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   148( 120+27  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    41(  36+5   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36edee5fd0 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      92/   95 |CallsAndLoop/Thres   40795/40582 |Inval#             16 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   132( 108+24  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ed5ee990 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     295/  298 |CallsAndLoop/Thres   33029/32981 |Inval#             10 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   135( 108+27  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    42(  35+6   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36edef5c90 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres      98/  101 |CallsAndLoop/Thres   43158/42581 |Inval#             17 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   131( 103+28  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_mul <opt>                                               |ASTSize     247/  247 |Time    53(  36+17  )ms |DirectCallNodes I    0/D    2 |GraalNodes   213/  866 |CodeSize         3370 |CodeAddress 0x7f36ed9b8950 |Source        nn.c:43 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   143( 119+24  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ed8fb310 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    54(  43+10  )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed895a50 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     111/  114 |CallsAndLoop/Thres   47580/47387 |Inval#             18 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     346/  349 |CallsAndLoop/Thres   37268/37153 |Inval#             11 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   115(  95+20  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36edec3590 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    39(  30+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed131c50 |Source nn_linear.c:59 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     357/  360 |CallsAndLoop/Thres   38930/38897 |Inval#             12 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     115/  118 |CallsAndLoop/Thres   49196/48985 |Inval#             19 
[truffle] opt done         @nn_mul_kara <opt>                                          |ASTSize     579/ 1947 |Time   686( 294+392 )ms |DirectCallNodes I    6/D   13 |GraalNodes  3628/11240 |CodeSize        47550 |CodeAddress 0x7f36ee52bd90 |Source nn_subquadratic.c:33 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   136( 110+26  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    43(  35+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed95f690 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     123/  126 |CallsAndLoop/Thres   52367/51969 |Inval#             20 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   140( 110+29  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   133( 107+26  )ms |DirectCallNodes I    4/D    1 |GraalNodes   801/  763 |CodeSize         2408 |CodeAddress 0x7f36ee5d9710 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     383/  386 |CallsAndLoop/Thres   42921/42903 |Inval#             13 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    46(  37+9   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee5dbdd0 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     126/  129 |CallsAndLoop/Thres   54744/54525 |Inval#             21 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   130( 106+24  )ms |DirectCallNodes I    4/D    1 |GraalNodes   801/  763 |CodeSize         2408 |CodeAddress 0x7f36ee625410 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    45(  37+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee62ad10 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     131/  134 |CallsAndLoop/Thres   56358/56244 |Inval#             22 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     393/  396 |CallsAndLoop/Thres   44978/44639 |Inval#             14 
[truffle] opt deopt        @nn_sub1                                                    |ASTSize     399/  399 |Calls/Thres    1018/    3 |CallsAndLoop/Thres    1019/ 1000 |Inval#              0 
[truffle] opt done         @nn_sub1 <opt>                                              |ASTSize     399/  399 |Time   102(  75+28  )ms |DirectCallNodes I    0/D    0 |GraalNodes   543/  715 |CodeSize         2169 |CodeAddress 0x7f36ee650b10 |Source nn_linear.c:316 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   124(  98+25  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ee6692d0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    34(  28+6   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee66e190 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     136/  139 |CallsAndLoop/Thres   58116/57962 |Inval#             23 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     401/  404 |CallsAndLoop/Thres   45799/45643 |Inval#             15 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    41(  34+7   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee672f10 |Source nn_linear.c:59 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   101(  81+20  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ee691cd0 |Source nn_linear.c:76 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     139/  142 |CallsAndLoop/Thres   60090/59880 |Inval#             24 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     404/  407 |CallsAndLoop/Thres   46795/46691 |Inval#             16 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   130( 107+23  )ms |DirectCallNodes I    4/D    1 |GraalNodes   801/  763 |CodeSize         2408 |CodeAddress 0x7f36ee6e93d0 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     409/  412 |CallsAndLoop/Thres   48281/47973 |Inval#             17 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    41(  35+5   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ee70d950 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     142/  145 |CallsAndLoop/Thres   61585/61486 |Inval#             25 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   136( 111+25  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7f36ee775a90 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     422/  425 |CallsAndLoop/Thres   50391/50351 |Inval#             18 
[truffle] opt invalidated  @nn_test_random2                                            |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random2                                            |ASTSize     705/ 1413 |Time    45(  36+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress       0x0 |Source nn_linear.c:59 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time   129( 106+23  )ms |DirectCallNodes I    4/D    1 |GraalNodes   801/  763 |CodeSize         2408 |CodeAddress 0x7f36ed7d26d0 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres     434/  437 |CallsAndLoop/Thres   51011/51011 |Inval#             19 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    36(  30+5   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed131c50 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres     151/  154 |CallsAndLoop/Thres   65813/65787 |Inval#             26 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time   121(  96+25  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @malloc <opt>                                               |ASTSize       3/    3 |Time    10(   6+4   )ms |DirectCallNodes I    0/D    0 |GraalNodes    45/   88 |CodeSize          299 |CodeAddress 0x7f36eda48990 |Source            n/a 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    48(  40+8   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7f36ed895a50 |Source nn_linear.c:59
# after some time ...
[truffle] opt done         @randoms_of_len                                             |ASTSize    1163/ 1169 |Time   109(  46+64  )ms |DirectCallNodes I    2/D    1 |GraalNodes  1529/ 3621 |CodeSize        16374 |CodeAddress       0x0 |Source     test.c:199 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time    81(  68+13  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7fbe4915ae90 |Source nn_linear.c:76 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres   12087/12090 |CallsAndLoop/Thres 1508818/1508769 |Inval#            907 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres    4144/ 4147 |CallsAndLoop/Thres 1705664/1705255 |Inval#            844 
[truffle] opt invalidated  @nn_test_random                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @nn_test_random                                             |ASTSize     327/ 1035 |Time    68(  56+13  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress       0x0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    25(  21+4   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7fbe4a611010 |Source nn_linear.c:59 
[truffle] opt invalidated  @randoms_of_len                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @randoms_of_len                                             |ASTSize    1163/ 1169 |Time   114(  47+67  )ms |DirectCallNodes I    2/D    1 |GraalNodes  1529/ 3621 |CodeSize        16374 |CodeAddress       0x0 |Source     test.c:199 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres    4147/ 4150 |CallsAndLoop/Thres 1707961/1707942 |Inval#            845 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time    66(  55+10  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7fbe49546cd0 |Source nn_linear.c:76 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    24(  20+4   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7fbe49a62890 |Source nn_linear.c:59 
[truffle] opt deopt        @nn_test_random2                                            |ASTSize     705/  705 |Calls/Thres    4150/ 4153 |CallsAndLoop/Thres 1708622/1708439 |Inval#            846 
[truffle] opt deopt        @kiss_word <opt>                                            |ASTSize     177/  177 |Calls/Thres    3899/    3 |CallsAndLoop/Thres    3899/ 1000 |Inval#              0 
[truffle] opt deopt        @nn_test_random                                             |ASTSize     327/  327 |Calls/Thres   12110/12113 |CallsAndLoop/Thres 1511314/1511295 |Inval#            908 
[truffle] opt invalidated  @randoms_of_len                                             |SourceClass OptimizedAssumption |Source Assumption(invalid, name=null) |Reason assumption already invalidated when installing code 
[truffle] opt done         @randoms_of_len                                             |ASTSize    1163/ 1169 |Time   118(  55+63  )ms |DirectCallNodes I    2/D    1 |GraalNodes  1529/ 3621 |CodeSize        16374 |CodeAddress       0x0 |Source     test.c:199 
[truffle] opt done         @nn_test_random2 <opt>                                      |ASTSize     705/ 1413 |Time    26(  19+6   )ms |DirectCallNodes I    4/D    0 |GraalNodes   208/  245 |CodeSize          420 |CodeAddress 0x7fbe49d452d0 |Source nn_linear.c:59 
[truffle] opt done         @nn_test_random <opt>                                       |ASTSize     327/ 1035 |Time    80(  64+16  )ms |DirectCallNodes I    4/D    1 |GraalNodes   802/  763 |CodeSize         2408 |CodeAddress 0x7fbe498cc950 |Source nn_linear.c:76
# ....
grimmerm commented 6 years ago

can you trace the deoptimization and point me to the place where the deop happens?

pointhi commented 6 years ago

Similar problem:

https://github.com/swenson/sort

export LLVM_COMPILER=clang
CC=wllvm make multidemo
extract-bc multidemo
mx --jdk jvmci --dynamicimports=/compiler lli multidemo.bc  -Dgraal.TraceTruffleCompilation=true -Dgraal.TraceTruffleCompilation=true
pointhi commented 6 years ago
$ uname -a
Linux JKU-SSW-Thomas 4.15.3-1-ARCH #1 SMP PREEMPT Mon Feb 12 23:01:17 UTC 2018 x86_64 GNU/Linux
$ clang -v
clang version 5.0.1 (tags/RELEASE_501/final)
Target: x86_64-unknown-linux-gnu

Sulong, Graal, Truffle, JVMCI all updated to the current version

rschatz commented 6 years ago

I have identified the problem: It seems due to inlining, it's possible that the same SSA value has two different debug types at the same time.

Currently Sulong assumes that any value in bitcode has a single compile-time constant type. The deoptimizations come from the fact that it's always "toggling" between two types, so it's not compile-time constant anymore. I'd rather not drop the requirement for this to be compile-time constant, because that would incur runtime cost. We'll have to somehow associate the type with the code position to make it constant again. I'll look into that, but it might take a bit.

A workaround until this is fixed properly would be to compile the bitcode with debug information disabled.

zapster commented 6 years ago

This is solved by commit bb2850fbb4d2863f1ae9a80394ce3bbba6c7d449.