RFR: 8224221: add memprotect calls to event log
Baesken, Matthias
matthias.baesken at sap.com
Fri May 24 13:03:13 UTC 2019
Thanks for the review, I added an example event log entry to the bug .
I also added a short info that the mprotect calls are added to the logs.
Best regards, Matthias
> -----Original Message-----
> From: Doerr, Martin
> Sent: Freitag, 24. Mai 2019 10:03
> To: David Holmes <david.holmes at oracle.com>; Baesken, Matthias
> <matthias.baesken at sap.com>; 'hotspot-dev at openjdk.java.net' <hotspot-
> dev at openjdk.java.net>
> Subject: RE: RFR: 8224221: add memprotect calls to event log
>
> Hi Matthias,
>
> webrev 4 looks good to me.
> Can you add an example (log message) to the bug, please?
>
> Best regards,
> Martin
>
>
> > -----Original Message-----
> > From: hotspot-dev <hotspot-dev-bounces at openjdk.java.net> On Behalf
> Of
> > David Holmes
> > Sent: Freitag, 24. Mai 2019 08:46
> > To: Baesken, Matthias <matthias.baesken at sap.com>; 'hotspot-
> > dev at openjdk.java.net' <hotspot-dev at openjdk.java.net>
> > Subject: Re: RFR: 8224221: add memprotect calls to event log
> >
> > Hi Matthias,
> >
> > On 23/05/2019 11:25 pm, Baesken, Matthias wrote:
> > >>>>
> > >>>> This is starting to look a bit inconsistent. If you want to log
> > >>>> VirtualProtect calls then there are more of them than just in
> > >>>> guard_memory and unguard_memory. So I'm unclear on the intent
> here
> > -
> > >> is
> > >>>> it to log all "memory protection" actions or only to log those that
> > >>>> pertain to specific semantic actions?
> > >>>
> > >>> My Intention was to cover Windows as well, however it looks like
> there
> > >> are more VirtualProtect calls (9) in os_windows.cpp than mprotects
> in
> > >> os_linux.cpp (just 1 in linux_mprotect).
> > >>> But maybe it is better to omit VirtualProtect / os_windows in this
> patch ,
> > >> no problem.
> > >>> What do you think ?
> > >>
> > >> I think you need to decide what this work is trying to log - is it
> > >> "mprotect" calls or is it "memory protection" calls? Or something else.
> > >
> > > Hi David,
> > >
> > > Let's concentrate on the mprotects !
> > >
> > > http://cr.openjdk.java.net/~mbaesken/webrevs/8224221.4/
> >
> > Okay so basically non-Windows support. Please make this clear in the bug
> > report.
> >
> > Those changes seem fine.
> >
> > >>>
> > >>> Yes , if I keep the eventlog_init() where it is, I miss a few early
> > >> mprotect calls .
> > >>> I observed this in our tests .
> > >>>
> > >>> However when moving forward eventlog_init like I did in the first
> rev.
> > (
> > >>
> >
> http://cr.openjdk.java.net/~mbaesken/webrevs/8224221.0/src/hotspot/sha
> > >> re/runtime/thread.cpp.frames.html ) ,
> > >>> I run into " assert(os::mutex_init_done()) failed: Too early! "
> > >>> Mutex_init is done in os::init_2 , which is called from
> > >>>
> > >>> Threads::create_vm() {
> > >>> ...
> > >>> 3740 // Initialize the os module after parsing the args
> > >>> 3741 jint os_init_2_result = os::init_2();
> > >>> 3742 if (os_init_2_result != JNI_OK) return os_init_2_result;
> > >>> ...
> > >>> }
> > >>>
> > >>> So I could place eventlog_init() after os::init_2 instead of the start
> of
> > >> Threads::create_vm .
> > >>
> > >> I added an assert(false) in linux_mprotect to see where it is first
> > >> called from (not 100% accurate as different flags may trigger other code
> > >> paths) and found it was called from initialize_assert_poison() here:
> > >>
> > >> // Initialize the os module after parsing the args
> > >> jint os_init_2_result = os::init_2();
> > >> if (os_init_2_result != JNI_OK) return os_init_2_result;
> > >>
> > >> #ifdef CAN_SHOW_REGISTERS_ON_ASSERT
> > >> // Initialize assert poison page mechanism.
> > >> if (ShowRegistersOnAssert) {
> > >> initialize_assert_poison();
> > >> }
> > >> #endif // CAN_SHOW_REGISTERS_ON_ASSERT
> > >>
> > >> So if you move your event_init to before the #ifdef it not only should
> > >> work okay, but it also shouldn't normally miss any calls to mprotect.
> > >> Obviously more extensive testing would be needed.
> > >>
> > >
> > > Thanks for looking into it .
> > > Unfortunately this causes another assertion (shows up already in the
> > fastdebug build when using the new JVM) .
> > >
> > >
> > > jdk/src/hotspot/share/runtime/thread.hpp:818), pid=53146, tid=53268
> > > assert(current != __null) failed: Thread::current() called on detached
> > thread
> >
> > Okay so that's a different problem: the event log uses a mutex and that
> > needs an attached thread. So you can't use the event_log before the main
> > thread has attached even if you've initialized the event log. So even if
> > you keep the eventlog_init() where it is inside vm_init_globals(),
> > there's a small risk you could still try to use the event log before the
> > main thread attaches:
> >
> > // Initialize global data structures and create system classes in heap
> > vm_init_globals();
> >
> > #if INCLUDE_JVMCI
> > if (JVMCICounterSize > 0) {
> > JavaThread::_jvmci_old_thread_counters = NEW_C_HEAP_ARRAY(jlong,
> > JVMCICounterSize, mtInternal);
> > memset(JavaThread::_jvmci_old_thread_counters, 0, sizeof(jlong) *
> > JVMCICounterSize);
> > } else {
> > JavaThread::_jvmci_old_thread_counters = NULL;
> > }
> > #endif // INCLUDE_JVMCI
> >
> > // Attach the main thread to this os thread
> > JavaThread* main_thread = new JavaThread();
> > main_thread->set_thread_state(_thread_in_vm);
> > main_thread->initialize_thread_current();
> > // must do this before set_active_handles
> > main_thread->record_stack_base_and_size();
> > main_thread->register_thread_stack_with_NMT();
> > main_thread->set_active_handles(JNIHandleBlock::allocate_block());
> >
> > if (!main_thread->set_as_starting_thread()) {
> > vm_shutdown_during_initialization(
> > "Failed necessary internal
> > allocation. Out of swap space");
> > main_thread->smr_delete();
> > *canTryAgain = false; // don't let caller call JNI_CreateJavaVM again
> > return JNI_ENOMEM;
> > }
> >
> > // Enable guard page *after* os::create_main_thread(), otherwise it
> would
> > // crash Linux VM, see notes in os_linux.cpp.
> > main_thread->create_stack_guard_pages();
> >
> > Fortunately the sequence of mprotect calls seems to be:
> > - initialize_assert_poison() (if enabled and a debug build)
> > - two via SafepointMechanism::initialize();
> > - main_thread->create_stack_guard_pages(); (around 10 calls in here)
> >
> > So it appears that currently leaving the eventlog_init() where it is,
> > and ensuring you don't log before initialization, that things will work
> > okay. I have some reservations about what may be possible if the main
> > thread takes a lock etc before its guard pages have been set up - but I
> > think that should be safe. There may also be an issue if we take the
> > vm_exit path - but as of now there are no mprotect calls if we do that.
> >
> > David
> > -----
> >
> > > V [libjvm.so+0x18d000f] VMError::report_and_die(Thread*, void*, char
> > const*, int, char const*, char const*, __va_list_tag*)+0x2f
> > > V [libjvm.so+0xa7f051] report_vm_error(char const*, int, char const*,
> > char const*, ...)+0x111
> > > V [libjvm.so+0x136e04e]
> Monitor::lock_without_safepoint_check()+0x1be
> > > V [libjvm.so+0xaacf07] Events::log(Thread*, char const*, ...)+0xe7
> > > V [libjvm.so+0x140c18b] linux_mprotect(char*, unsigned long,
> int)+0x12b
> > > V [libjvm.so+0xa84197] initialize_assert_poison()+0xc7
> > > V [libjvm.so+0x1810322] Threads::create_vm(JavaVMInitArgs*,
> > bool*)+0x2b2
> > > V [libjvm.so+0xf07b59] JNI_CreateJavaVM+0x69
> > > C [libjli.so+0x42b6] JavaMain+0x86
> > > C [libjli.so+0x8319] ThreadJavaMain+0x9
> > >
> > > Best regards, Matthias
> > >
More information about the hotspot-dev
mailing list