Back to work...JDK8

Sat Sep 15 15:15:38 PDT 2012

Things like this worry me a bit too, but there's only a couple of them :)

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