PING: Could you review it? http://cr.openjdk.java.net/~ysuenaga/JDK-8140556/webrev.04/
I need reviewer and sponsor. Thanks, Yasumasa 2015/11/15 21:50 "Yasumasa Suenaga" <yasue...@gmail.com>: > > PING: Could you review it? > http://cr.openjdk.java.net/~ysuenaga/JDK-8140556/webrev.04/ > > Yasumasa > > > On 2015/11/05 23:50, Yasumasa Suenaga wrote: >>>> >>>> _post_initialized would be a more accurate name. >> >> >> I've fixed it in new webrev: >> http://cr.openjdk.java.net/~ysuenaga/JDK-8140556/webrev.04/ >> >> I will send changeset to Marcus if this changeset is reviewed. >> >> >> Thanks. >> >> Yasumasa >> >> >> On 2015/11/05 23:38, Marcus Larsson wrote: >>> >>> Hey, >>> >>> On 2015-11-05 04:50, David Holmes wrote: >>>> >>>> On 5/11/2015 1:30 PM, Yasumasa Suenaga wrote: >>>>> >>>>> I've uploaded new webrev: >>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-8140556/webrev.03/ >>>>> >>>>> I added _initialized to LogConfiguration. >>>>> LogConfiguration::post_initialize() will be called after main thread >>>>> initialization. >>>>> So _initialized set to true in this function, and we can check this flag >>>>> at rotation. >>>>> >>>>> Could you review it? >>> >>> >>> Looks OK to me. This is much better than checking for Thread::current() != NULL in is_rotatable(), IMHO. >>> >>>> >>>> _post_initialized would be a more accurate name. >>>> >>>> This of course works, but I don't know whether the additional delay in allowing rotation will impact anything. >>> >>> >>> It shouldn't. If anyone ever generates that much logging during startup they will have to accept that the first rotated log won't be properly sized, that's all. >>> >>> Thanks, >>> Marcus >>> >>>> >>>> Thanks, >>>> David >>>> >>>>> >>>>> Thanks, >>>>> >>>>> Yasumasa >>>>> >>>>> >>>>> On 2015/11/02 22:32, Yasumasa Suenaga wrote: >>>>>> >>>>>> Marcus, David, >>>>>> >>>>>> I've uploaded new webrev: >>>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-8140556/webrev.02/ >>>>>> >>>>>> Could you review it? >>>>>> >>>>>> >>>>>>>>>>> Still missing the renaming of rotate_all_logfile to >>>>>>>>>>> rotate_all_outputs. >>>>>> >>>>>> >>>>>> I've fixed. >>>>>> >>>>>> >>>>>>>>> Small typo, please make that is_rotatable(). >>>>>> >>>>>> >>>>>> I've added, and have used at LogConfiguration::rotate_all_outputs(). >>>>>> >>>>>> >>>>>>> You can't safely lock a mutex until the current thread has attached >>>>>>> to the VM and Thread::current() returns non-null (that is what >>>>>>> Thread::initialize_thread_local_storage() currently does). You may >>>>>>> get away with it, particularly in product builds, during VM >>>>>>> initialization, as the fast-lock path doesn't require access to >>>>>>> Thread::current(). >>>>>> >>>>>> >>>>>> I will check whether Thread::current() is NULL or not at >>>>>> LogFileOutput::is_rotatable() >>>>>> is_rotatable() is called at LogFileOutput::rotate() before locking >>>>>> _rotation_lock. >>>>>> So we can avoid crash/assert which is related to TLS. >>>>>> >>>>>> >>>>>> Thanks, >>>>>> >>>>>> Yasumasa >>>>>> >>>>>> >>>>>> On 2015/11/02 11:11, David Holmes wrote: >>>>>>> >>>>>>> On 1/11/2015 1:10 AM, Yasumasa Suenaga wrote: >>>>>>>>> >>>>>>>>> This in turn means that we are logging before the thread local storage >>>>>>>>> has been initialized, and the JVM will crash/hit the assert because we >>>>>>>>> are trying to take the rotation lock. >>>>>>>> >>>>>>>> >>>>>>>> I guess that you are saying about class member (not TLS - e.g. >>>>>>>> pthread_setspecific()). >>>>>>> >>>>>>> >>>>>>> You can't safely lock a mutex until the current thread has attached >>>>>>> to the VM and Thread::current() returns non-null (that is what >>>>>>> Thread::initialize_thread_local_storage() currently does). You may >>>>>>> get away with it, particularly in product builds, during VM >>>>>>> initialization, as the fast-lock path doesn't require access to >>>>>>> Thread::current(). >>>>>>> >>>>>>> David >>>>>>> >>>>>>>> Most of fields (include _rotation_lock) in LogFileOutput are >>>>>>>> initialized >>>>>>>> at c'tor. >>>>>>>> Other field (_stream) is initialized at LogFileOutput::initialize(). >>>>>>>> >>>>>>>> We can avoid problem if we can move initialize() to c'tor because >>>>>>>> LogFileOutput >>>>>>>> will be instantiated at LogConfiguration::new_output(). >>>>>>>> >>>>>>>> Currently, LogFileOutput will be added to LogConfiguration::_outputs >>>>>>>> and >>>>>>>> to LogTagSet after calling LogFileOutput::initialize(). >>>>>>>> I wonder why we cannot avoid crash/assert with current >>>>>>>> implementation... >>>>>>>> >>>>>>>> >>>>>>>> I will keep current implementation about _rotation_lock if the above is >>>>>>>> incorrect. >>>>>>>> >>>>>>>> >>>>>>>> Thanks, >>>>>>>> >>>>>>>> Yasumasa >>>>>>>> >>>>>>>> >>>>>>>> On 2015/10/31 0:31, Marcus Larsson wrote: >>>>>>>>> >>>>>>>>> Hey, >>>>>>>>> >>>>>>>>> On 2015-10-30 15:39, Yasumasa Suenaga wrote: >>>>>>>>>> >>>>>>>>>> Hi Marcus, >>>>>>>>>> >>>>>>>>>> Thank you for your comment. >>>>>>>>>> >>>>>>>>>> >>>>>>>>>>> Still missing the renaming of rotate_all_logfile to >>>>>>>>>>> rotate_all_outputs. >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> Sorry, I will fix. >>>>>>>>>> >>>>>>>>> >>>>>>>>> Thanks! >>>>>>>>> >>>>>>>>>> >>>>>>>>>>> This rotate function works I guess, but it will probably need some >>>>>>>>>>> rework once there are other types of log outputs (rotate doesn't >>>>>>>>>>> make sense on all types of log outputs). >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> I will add is_rotetable() to LogOutput as virtual function. >>>>>>>>>> This function return false (can not rotate) by default, return true >>>>>>>>>> if _file_count is >>>>>>>>>> greater than 0 in LogFileOutput. >>>>>>>>>> >>>>>>>>>> LogConfiguration::rotate_all_outputs() will rotate if this function >>>>>>>>>> returns true. >>>>>>>>>> >>>>>>>>> >>>>>>>>> Small typo, please make that is_rotatable(). >>>>>>>>> >>>>>>>>>> >>>>>>>>>>> If we configure a rotated file output and then log something on that >>>>>>>>>>> output before thread local storage initialization is complete, we >>>>>>>>>>> will crash/hit an assert. The previous implementation avoided this >>>>>>>>>>> as long as no rotation was needed before this initialization was >>>>>>>>>>> complete. (This can be triggered using the following arguments >>>>>>>>>>> "-Xlog:all=trace:file.txt::filesize=10,filecount=2 -Xlog:invalid", >>>>>>>>>>> for example.) >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> I do not think so. >>>>>>>>>> Each -Xlog option creates unique instance of LogOutput (and >>>>>>>>>> subclass). >>>>>>>>>> So they are isolated. >>>>>>>>> >>>>>>>>> >>>>>>>>> My example includes a second (and intentionally incorrect) -Xlog >>>>>>>>> option only to trigger logging on the newly configured rotating >>>>>>>>> LogFileOutput. This will cause some logging about the invalid -Xlog >>>>>>>>> argument, and this logging happens during the argument parsing. This >>>>>>>>> in turn means that we are logging before the thread local storage has >>>>>>>>> been initialized, and the JVM will crash/hit the assert because we are >>>>>>>>> trying to take the rotation lock. This has nothing to do with >>>>>>>>> concurrent fprintfs or freopens, even if that is a problem. >>>>>>>>> >>>>>>>>>> >>>>>>>>>> However, we might have to rotate at safepoint. >>>>>>>>> >>>>>>>>> >>>>>>>>> Doing stuff at a safepoint will not give us much in this case. There >>>>>>>>> are threads that continue execution through a safepoint, which means >>>>>>>>> we will see log calls being made even during this time. >>>>>>>>> >>>>>>>>>> Currently, LogOutput might be used by multiple threads concurrently. >>>>>>>>>> If we rotate log when another thread is writing string to output, we >>>>>>>>>> encounter unexpected behavior. >>>>>>>>>> >>>>>>>>>> LogFileOutput::rotate() uses freopen(). >>>>>>>>>> LogFileStreamOutput::write() uses vfprintf() through jio_fprintf(). >>>>>>>>>> freopen() and vfprintf() are not atomic. >>>>>>>>> >>>>>>>>> >>>>>>>>> You're right. There seems to be an overlooked concurrency issue with >>>>>>>>> vfprintfs during freopen. I don't think we should resolve this as part >>>>>>>>> of this particular fix, so instead I'll create a separate issue for >>>>>>>>> it. >>>>>>>>> >>>>>>>>>> >>>>>>>>>> I think that cause of crash/assertion which you say is it. >>>>>>>>>> (GC log will be rotated at safepoint.) >>>>>>>>>> >>>>>>>>> >>>>>>>>> See my comment above for what crash/assert I'm talking about. >>>>>>>>> >>>>>>>>> Thanks, >>>>>>>>> Marcus >>>>>>>>> >>>>>>>>>> >>>>>>>>>> Thanks, >>>>>>>>>> >>>>>>>>>> Yasumasa >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> On 2015/10/29 23:58, Marcus Larsson wrote: >>>>>>>>>>> >>>>>>>>>>> Hi, >>>>>>>>>>> >>>>>>>>>>> On 2015-10-29 15:01, Yasumasa Suenaga wrote: >>>>>>>>>>>> >>>>>>>>>>>> Hi Marcus, >>>>>>>>>>>> >>>>>>>>>>>> Thank you for your comment. >>>>>>>>>>>> >>>>>>>>>>>>> I'll sponsor it. >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> Thank you so much! >>>>>>>>>>>> I've uploaded new webrev: >>>>>>>>>>>> >>>>>>>>>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-8140556/webrev.01/ >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> Still missing the renaming of rotate_all_logfile to >>>>>>>>>>> rotate_all_outputs. >>>>>>>>>>> >>>>>>>>>>>>> logConfiguration.cpp/hpp: >>>>>>>>>>>>> >>>>>>>>>>>>> * I don't think we should rely on the archive_name or the output's >>>>>>>>>>>>> name to decide whether or not an output should be rotated. It >>>>>>>>>>>>> would be better to introduce an is_rotated() test function in >>>>>>>>>>>>> LogOutput that could be used here. >>>>>>>>>>>>> >>>>>>>>>>>>> * rotate_all_logfile() should be renamed to rotate_all_outputs(). >>>>>>>>>>>>> Currently there are only LogFileOutputs (other than >>>>>>>>>>>>> stdout/stderr), but in the future there might be other types of >>>>>>>>>>>>> outputs so I prefer having a more general name. >>>>>>>>>>>>> Also, please use static_cast<LogFileOutput*> instead of the >>>>>>>>>>>>> C-style cast. (Additional logic will be required here once more >>>>>>>>>>>>> types of log outputs are added, but I don't think we need to worry >>>>>>>>>>>>> about this right now.) >>>>>>>>>>>>> >>>>>>>>>>>>> * Don't print an error if an output is not rotatable, since it's >>>>>>>>>>>>> not an error to have some log outputs rotated while others are >>>>>>>>>>>>> not. If you really want some traceability here I suggest adding >>>>>>>>>>>>> log messages on trace level, tagged with 'logging'. >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> I added LogOutput::rotate(bool) as virtual function. >>>>>>>>>>>> This function works nothing by default, but will rotate all logs at >>>>>>>>>>>> LogFileOutput. >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> This rotate function works I guess, but it will probably need some >>>>>>>>>>> rework once there are other types of log outputs (rotate doesn't >>>>>>>>>>> make sense on all types of log outputs). >>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> If true is passed to this function, all files will be rotated. >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>>> logDiagnosticCommand.cpp/hpp: >>>>>>>>>>>>> >>>>>>>>>>>>> * I think the description could be improved to something like >>>>>>>>>>>>> "Lists current log configuration, enables/disables/configures a >>>>>>>>>>>>> log output, or disables/rotates all logs." >>>>>>>>>>>>> >>>>>>>>>>>>> * The rotate option description should clarify that all logs will >>>>>>>>>>>>> be rotated ("current log" is too ambiguous). >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> I've fixed. >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> Great, thanks! >>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>>> logFileOutput.cpp/hpp: >>>>>>>>>>>>> >>>>>>>>>>>>> * Moving the MutexLocker like this introduces a race condition >>>>>>>>>>>>> where a log might be rotated multiple times by different threads, >>>>>>>>>>>>> instead of just once. >>>>>>>>>>>>> Instead of making the rotate() function public and moving the >>>>>>>>>>>>> mutexlocker, I suggest adding something like a public >>>>>>>>>>>>> force_rotation() function that grabs the lock and calls the >>>>>>>>>>>>> private rotate(). >>>>>>>>>>>>> >>>>>>>>>>>>> * Given the addition of is_rotated() in LogOutput, then >>>>>>>>>>>>> get_archive_name() should be removed. >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> I moved MutexLocker and should_rotate() to rotate(). >>>>>>>>>>>> I think this change can avoid race condition. >>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> There is a subtle problem with taking the lock to check if we should >>>>>>>>>>> rotate. If we configure a rotated file output and then log something >>>>>>>>>>> on that output before thread local storage initialization is >>>>>>>>>>> complete, we will crash/hit an assert. The previous implementation >>>>>>>>>>> avoided this as long as no rotation was needed before this >>>>>>>>>>> initialization was complete. (This can be triggered using the >>>>>>>>>>> following arguments >>>>>>>>>>> "-Xlog:all=trace:file.txt::filesize=10,filecount=2 -Xlog:invalid", >>>>>>>>>>> for example.) >>>>>>>>>>> >>>>>>>>>>> Thanks, >>>>>>>>>>> Marcus >>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> Thanks, >>>>>>>>>>>> >>>>>>>>>>>> Yasumasa >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> On 2015/10/27 21:17, Marcus Larsson wrote: >>>>>>>>>>>>> >>>>>>>>>>>>> Hi, >>>>>>>>>>>>> >>>>>>>>>>>>> On 2015-10-27 01:03, Yasumasa Suenaga wrote: >>>>>>>>>>>>>> >>>>>>>>>>>>>> Hi Marcus, >>>>>>>>>>>>>> >>>>>>>>>>>>>> Thank you for replying. >>>>>>>>>>>>>> >>>>>>>>>>>>>> I filed this feature to JBS and change subject of this email. >>>>>>>>>>>>>> Could you be a sponsor and review it? >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> I'll sponsor it. >>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-8140556/webrev.00/ >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> logConfiguration.cpp/hpp: >>>>>>>>>>>>> >>>>>>>>>>>>> * I don't think we should rely on the archive_name or the output's >>>>>>>>>>>>> name to decide whether or not an output should be rotated. It >>>>>>>>>>>>> would be better to introduce an is_rotated() test function in >>>>>>>>>>>>> LogOutput that could be used here. >>>>>>>>>>>>> >>>>>>>>>>>>> * rotate_all_logfile() should be renamed to rotate_all_outputs(). >>>>>>>>>>>>> Currently there are only LogFileOutputs (other than >>>>>>>>>>>>> stdout/stderr), but in the future there might be other types of >>>>>>>>>>>>> outputs so I prefer having a more general name. >>>>>>>>>>>>> Also, please use static_cast<LogFileOutput*> instead of the >>>>>>>>>>>>> C-style cast. (Additional logic will be required here once more >>>>>>>>>>>>> types of log outputs are added, but I don't think we need to worry >>>>>>>>>>>>> about this right now.) >>>>>>>>>>>>> >>>>>>>>>>>>> * Don't print an error if an output is not rotatable, since it's >>>>>>>>>>>>> not an error to have some log outputs rotated while others are >>>>>>>>>>>>> not. If you really want some traceability here I suggest adding >>>>>>>>>>>>> log messages on trace level, tagged with 'logging'. >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> logDiagnosticCommand.cpp/hpp: >>>>>>>>>>>>> >>>>>>>>>>>>> * I think the description could be improved to something like >>>>>>>>>>>>> "Lists current log configuration, enables/disables/configures a >>>>>>>>>>>>> log output, or disables/rotates all logs." >>>>>>>>>>>>> >>>>>>>>>>>>> * The rotate option description should clarify that all logs will >>>>>>>>>>>>> be rotated ("current log" is too ambiguous). >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> logFileOutput.cpp/hpp: >>>>>>>>>>>>> >>>>>>>>>>>>> * Moving the MutexLocker like this introduces a race condition >>>>>>>>>>>>> where a log might be rotated multiple times by different threads, >>>>>>>>>>>>> instead of just once. >>>>>>>>>>>>> Instead of making the rotate() function public and moving the >>>>>>>>>>>>> mutexlocker, I suggest adding something like a public >>>>>>>>>>>>> force_rotation() function that grabs the lock and calls the >>>>>>>>>>>>> private rotate(). >>>>>>>>>>>>> >>>>>>>>>>>>> * Given the addition of is_rotated() in LogOutput, then >>>>>>>>>>>>> get_archive_name() should be removed. >>>>>>>>>>>>> >>>>>>>>>>>>> Thanks, >>>>>>>>>>>>> Marcus >>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> Thanks, >>>>>>>>>>>>>> >>>>>>>>>>>>>> Yasumasa >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> On 2015/10/26 18:56, Marcus Larsson wrote: >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Hi, >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Sorry for my late reply. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> I think being able to force rotation via jcmd seems like a good >>>>>>>>>>>>>>> feature. Files are currently opened in append mode so it should >>>>>>>>>>>>>>> already be possible to use external log rotation tools by >>>>>>>>>>>>>>> copying and truncating the files. Still I think it would be nice >>>>>>>>>>>>>>> to provide the jcmd for rotation as well. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> I can see some small issues with the implementation, but we can >>>>>>>>>>>>>>> deal with that during the review. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Thanks, >>>>>>>>>>>>>>> Marcus >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> On 2015-10-26 00:26, Yasumasa Suenaga wrote: >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Hi all, >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Have you ever seen my change? >>>>>>>>>>>>>>>> I (and my customers) need log rotation function via external >>>>>>>>>>>>>>>> tool. >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> I want to merge it by Feature Complete. >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Thanks, >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Yasumasa >>>>>>>>>>>>>>>> 2015/10/16 22:55 "Yasumasa Suenaga" <yasue...@gmail.com>: >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Hi all, >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> I contributed JDK-7090324: gclog rotation via external tool >>>>>>>>>>>>>>>>> to be >>>>>>>>>>>>>>>>> synchronized with >>>>>>>>>>>>>>>>> logrotated tool on Linux. >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> I think JEP 158 is in progress. >>>>>>>>>>>>>>>>> However, this JEP does not contain log rotation via external >>>>>>>>>>>>>>>>> tool in the >>>>>>>>>>>>>>>>> spec. >>>>>>>>>>>>>>>>> I want to rotate logs via jcmd in this JEP. >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> I've updated a patch for it: >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> http://cr.openjdk.java.net/~ysuenaga/jvmlogging-logrotate/ >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> This patch provides new option "rotate" in VM.log command. >>>>>>>>>>>>>>>>> If this change can be accepted, I will file it to JBS and send >>>>>>>>>>>>>>>>> RFR. >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Thanks, >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Yasumasa >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>
