Thank you David! I understood. I will try to create a patch for this enhancement with avoiding this issue.
Yasumasa 2015/11/02 11:12 "David Holmes" <david.hol...@oracle.com>: > 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 >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>> >>>>>>> >>>>> >>>
