Back to work...JDK8
Christian Thalinger
christian.thalinger at oracle.com
Mon Sep 17 15:13:44 PDT 2012
On Sep 15, 2012, at 3:15 PM, Charles Oliver Nutter <headius at headius.com> wrote:
> Things like this worry me a bit too, but there's only a couple of them :)
We need to find out why these guys deoptimize. Either add -XX:+TraceDeoptimization or -XX:+LogCompilation (for the latter the output is then in hotspot.log).
-- Chris
>
> made not compilable
> rubyjit.Sprockets::Helpers::RailsHelper$$asset_paths_E7117E440B09EADB5156B41F6B4DBBB1B0325779648508524::__file__
> (305 bytes)
>
> On Sat, Sep 15, 2012 at 3:08 PM, Charles Oliver Nutter
> <headius at headius.com> wrote:
>> Ok...I'm starting to poke a bit at JDK8 indy stuff to investigate perf
>> challenges. This thread will host my observations.
>>
>> Today I'm monitoring compilation logs, and the odd thing is that no
>> matter how long I run, PrintCompilation shows no signs of slowing. I
>> would assume that the compilation logs have a longer tail due to
>> tiering, but this seems excessive...it's just going on and on and on.
>>
>> That alone wouldn't worry me unless the JVM guys tell me to worry, but
>> then I see things like this over and over in the logs:
>>
>> 782140 40781 4
>> rubyjit.Rack::Session::Abstract::OptionsHash$$\=\{\}_CBCE967579AE6F1F55C9FF71BA8804158EC7869A648508524::__file__
>> (10 bytes)
>> 782144 40666 3
>> rubyjit.Rack::Session::Abstract::OptionsHash$$\=\{\}_CBCE967579AE6F1F55C9FF71BA8804158EC7869A648508524::__file__
>> (10 bytes) made not entrant
>> 782144 40781 4
>> rubyjit.Rack::Session::Abstract::OptionsHash$$\=\{\}_CBCE967579AE6F1F55C9FF71BA8804158EC7869A648508524::__file__
>> (10 bytes) made not entrant
>>
>> So this particular piece of code was compiled and then made not
>> entrant just 4ms later?
>>
>> I see this over and over and over again...in fact, late in this run,
>> perhaps 3/4 of the output lines are "made not entrant" or "made
>> zombie" and it just goes and goes and goes.
>>
>> Should I be concerned about this?
>>
>> Here's a dump of just a small portion of PrintCompilation output...
>>
>>
>> 1249422 50524 3
>> rubyjit.Rack::Request$$port_C30B05D438C56FB2565C807617206F20B98E2FE2648508524::__file__
>> (8 bytes)
>> 1249424 50525 3
>> rubyjit.Mime::Mimes$$symbols_100420D4F9BB142680CD7BB51F79045E1B619030648508524::__file__
>> (8 bytes)
>> 1249810 50526 4
>> rubyjit.ActiveRecord::LogSubscriber$$runtime=_CD1758211548CDD3492DAD323D979039EA4BC0ED648508524::__file__
>> (10 bytes)
>> 1249824 50315 3
>> rubyjit.ActiveRecord::LogSubscriber$$runtime=_CD1758211548CDD3492DAD323D979039EA4BC0ED648508524::__file__
>> (10 bytes) made not entrant
>> 1249825 50526 4
>> rubyjit.ActiveRecord::LogSubscriber$$runtime=_CD1758211548CDD3492DAD323D979039EA4BC0ED648508524::__file__
>> (10 bytes) made not entrant
>> 1249969 50527 3
>> rubyjit.Rack::Request$$GET_D76DBE1FD595925EB82EFFF575EF7260C14C3234648508524::__file__
>> (10 bytes)
>> 1249979 50528 3
>> rubyjit.ActionDispatch::Http::ParameterFilter$$compiled_filter_E4708BFBB5F4AD1657B9E83836ACFDC8B379C6DB648508524::__file__
>> (8 bytes)
>> 1249980 50474 4
>> rubyjit.#<Class:0x11e31625>$$asset_host_9AFC94A2EF47E84248C0CF85B1FB121C8BE53470648508524::__file__
>> (15 bytes) made zombie
>> 1249981 50529 3
>> rubyjit.ActionDispatch::Http::MimeNegotiation$$accepts_34A6B9527E85807CF247423542D5090EEF79001A648508524::__file__
>> (8 bytes)
>> 1249986 50530 3
>> rubyjit.ActionDispatch::Request$$method_EC59F5DFD894E82F7D9FF308054AAFB27CBE06AB648508524::__file__
>> (8 bytes)
>> 1249990 50305 3
>> rubyjit.Time$$minus_with_coercion_0F5E81EFFA4D396BAA52CFBEA356B55F32726771648508524::__file__
>> (10 bytes) made zombie
>> 1249992 50531 3
>> rubyjit$ActionController::Instrumentation$$process_action_1910D6D8DE3509AA678DB94D5691451BDEB50046648508524$block_0$RUBY$__file__::call
>> (13 bytes)
>> 1249998 50532 3
>> rubyjit.ActionController::Base$$_run_process_action_callbacks_1CEABAA1B8561DBCB7E134F0C024BA9AF08B531A648508524::__file__
>> (10 bytes)
>> 1250006 50533 3
>> rubyjit.ActionController::RequestForgeryProtection$$verified_request?_F8254ECDD493CE9EE41068057805A438954180D2648508524::__file__
>> (8 bytes)
>> 1250010 50106 3
>> rubyjit.Rack::Cache::CacheControl$$parse_AFED9E9AA448B78AAAB435669B61A6DADA1E75DF648508524::__file__
>> (10 bytes) made zombie
>> 1250014 50466 4
>> rubyjit.#<Module:0x7fe59880>$$locale_595319C157ACD915A0CB1B6E65F30E93C7D07C8C648508524::__file__
>> (8 bytes) made zombie
>> 1250016 50534 3
>> rubyjit.AbstractController::ViewPaths$$formats=_978E9AE3520041B33FAA82EED51F2733EDB234D5648508524::__file__
>> (10 bytes)
>> 1250018 50460 4
>> rubyjit.Rack::Cache::CacheControl$$parse_AFED9E9AA448B78AAAB435669B61A6DADA1E75DF648508524::__file__
>> (10 bytes) made zombie
>> 1250020 50276 3
>> rubyjit.Rack::Request$$scheme_C395E273E8CBF823C70EDCBBFC52DF10B6269234648508524::__file__
>> (8 bytes) made zombie
>> 1250020 50480 4
>> rubyjit.Rack::Request$$GET_D76DBE1FD595925EB82EFFF575EF7260C14C3234648508524::__file__
>> (128 bytes) made zombie
>> 1250026 50535 3
>> rubyjit.ActionView::LookupContext$$formats=_23E9B00E4B20D7AA8EB52AB22367DB3D1D37D83B648508524::__file__
>> (10 bytes)
>> 1250027 50230 3
>> rubyjit.ActionDispatch::Response$$\=\{\}_599DEC0207F25FEC51ECEBAAB8AD0B113E0E723F648508524::__file__
>> (10 bytes) made zombie
>> 1250027 50483 ! 4
>> rubyjit.ActiveRecord::QueryCache::BodyProxy$$close_49A8A831693348CE1AD5FA76FAB8945111B3A66D648508524::chained_0_ensure_1$RUBY$__ensure__
>> (288 bytes) made zombie
>> 1250029 50467 4
>> rubyjit.ActionDispatch::Response$$\=\{\}_599DEC0207F25FEC51ECEBAAB8AD0B113E0E723F648508524::__file__
>> (10 bytes) made zombie
>> 1250030 50477 4
>> rubyjit.ActionDispatch::Cookies::CookieJar$$write_cookie?_9E3227B1C7443C3E1A83A895F8360C3355FBB293648508524::__file__
>> (78 bytes) made zombie
>> 1250032 50470 4
>> rubyjit.Rack::Request$$scheme_C395E273E8CBF823C70EDCBBFC52DF10B6269234648508524::__file__
>> (8 bytes) made zombie
>> 1250033 50536 3
>> rubyjit.ActiveRecord::Railties::ControllerRuntime$$cleanup_view_runtime_456D2875A7FACEE5FA371C02BAC43C3DAAFCBACF648508524::__file__
>> (10 bytes)
>> 1250034 50469 4
>> rubyjit.Rack::Request$$host_with_port_1BFCC54D8B1D5C511532C418C20A536207812386648508524::__file__
>> (8 bytes) made zombie
>> 1250043 50459 4
>> rubyjit.Time$$minus_with_coercion_0F5E81EFFA4D396BAA52CFBEA356B55F32726771648508524::__file__
>> (10 bytes) made zombie
>> 1250046 50537 3
>> rubyjit.ActionController::Compatibility$$_normalize_options_7CA3A73C05A0C5FF6C8E1ABE7229208A9112D6C1648508524::__file__
>> (10 bytes)
>> 1250052 50485 ! 4
>> rubyjit.AbstractController::ViewPaths$$formats=_978E9AE3520041B33FAA82EED51F2733EDB234D5648508524::chained_0_rescue_1$RUBY$SYNTHETIC__file__
>> (132 bytes) made zombie
>> 1250056 50540 3
>> rubyjit.ActiveRecord::LogSubscriber$$runtime=_CD1758211548CDD3492DAD323D979039EA4BC0ED648508524::__file__
>> (10 bytes)
>> 1250063 50487 ! 4
>> rubyjit.JRuby::Rack::Response$$write_body_07A5A75A2293165FA8C89A81774EA8A99C41BC86648508524::chained_0_ensure_1$RUBY$__ensure__
>> (121 bytes) made zombie
>> 1250065 50294 3
>> rubyjit.#<Class:0x11e31625>$$asset_host_9AFC94A2EF47E84248C0CF85B1FB121C8BE53470648508524::__file__
>> (15 bytes) made zombie
>> 1250068 49501 3
>> rubyjit.#<Module:0x7fe59880>$$locale_595319C157ACD915A0CB1B6E65F30E93C7D07C8C648508524::__file__
>> (8 bytes) made zombie
>> 1250071 50457 4
>> rubyjit.ActionView::LookupContext::Accessors$$formats=_78A37AC39FB37666EC3F9F62B6DB1E3262AFBC3A648508524::__file__
>> (10 bytes) made zombie
>> 1250074 50538 3
>> rubyjit.ActiveSupport::MessageVerifier$$verify_106A8E70B6AB6FB45306BF36007F977DB562F73A648508524::__file__
>> (10 bytes)
>> 1250082 50361 3
>> rubyjit.ActiveRecord::Base$$connection_id_9C4C47560320F7F1D34FFF5A842A9C29CCBC6079648508524::__file__
>> (8 bytes) made zombie
>> 1250085 50543 4
>> rubyjit.Rack::ConditionalGet$$call_3F85FD32BC7EF9B82E5CDB21747EEED2925367BF648508524::__file__
>> (673 bytes)
>> 1250086 50544 4
>> rubyjit.ActionDispatch::Http::FilterParameters$$filtered_parameters_1269D86467F332ABCD2FF929C617771A476D8240648508524::__file__
>> (113 bytes)
>> 1250086 50104 3
>> rubyjit.ActionView::LookupContext::Accessors$$formats=_78A37AC39FB37666EC3F9F62B6DB1E3262AFBC3A648508524::__file__
>> (10 bytes) made zombie
>> 1250086 50456 4
>> rubyjit.AbstractController::ViewPaths$$lookup_context_E57E102D0848EE904F58857E10C71271E59F2F58648508524::__file__
>> (177 bytes) made zombie
>> 1250090 50482 4
>> rubyjit.ActiveSupport::TaggedLogging$$flush_FA9494CB3E6170368159536C8F58BF2FF3C95ECB648508524::__file__
>> (75 bytes) made zombie
>> 1250094 50461 4
>> rubyjit.ActiveRecord::Base$$connection_id_9C4C47560320F7F1D34FFF5A842A9C29CCBC6079648508524::__file__
>> (8 bytes) made zombie
>> 1250095 50539 3
>> rubyjit.ActiveSupport::MessageVerifier$$secure_compare_9370D1984C6C369D6E89440D65546223F1122013648508524::__file__
>> (12 bytes)
>> 1250103 50479 4
>> rubyjit.Rack::Cache::Context$$not_modified?_FAD2FE8BEB056EF57D809C367DCC84E53B5A13BE648508524::__file__
>> (305 bytes) made zombie
>> 1250103 50543 4
>> rubyjit.Rack::ConditionalGet$$call_3F85FD32BC7EF9B82E5CDB21747EEED2925367BF648508524::__file__
>> (673 bytes) made not entrant
>> 1250107 50462 ! 4
>> rubyjit.ActionDispatch::DebugExceptions$$call_6FBF31DE0A92B21EDCFACD7E5EA4DCB6CAA9F2A3648508524::chained_0_rescue_1$RUBY$SYNTHETIC__file__
>> (374 bytes) made zombie
>> 1250109 50231 3
>> rubyjit.Rack::Request$$host_with_port_1BFCC54D8B1D5C511532C418C20A536207812386648508524::__file__
>> (8 bytes) made zombie
>> 1250111 50541 3
>> rubyjit.JRuby::Rack::Response$$write_body_07A5A75A2293165FA8C89A81774EA8A99C41BC86648508524::__file__
>> (62 bytes)
>> 1250115 50476 4
>> rubyjit.ActionDispatch::Response$$initialize_FA88931767B4D2C0D575A7CAF7E60BD0042E4719648508524::__file__
>> (430 bytes) made zombie
>> 1250118 50481 4
>> rubyjit.ActionDispatch::Cookies::SignedCookieJar$$\=\{\}=_198968785F08CF05E82A1B2E5325FFDE0E5FC06E648508524::__file__
>> (272 bytes) made zombie
>> 1250122 50478 4
>> rubyjit.Time$$httpdate_3BE5FAE292F39996D5D83E6ABA3DE418245F893F648508524::__file__
>> (231 bytes) made zombie
> _______________________________________________
> mlvm-dev mailing list
> mlvm-dev at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/mlvm-dev
More information about the mlvm-dev
mailing list