RFR: 8146009: "pure virtual method called" with using new GC logging mechanism

[Thomas Stüfe]

Hi Marcus,

On Tue, Oct 11, 2016 at 11:41 AM, Marcus Larsson <marcus.larsson at oracle.com>
wrote:

> Hi Thomas,
>
> On 10/11/2016 11:13 AM, Thomas Stüfe wrote:
>
> Hi Markus,
>
> just a question whether I understand this correctly: Logging works already
> from static initialization on, but as no arguments are parsed yet, the
> default is to print out all warning and error level messages to stderr?
>
> If true, this may be potentially confusing, because there will always be a
> small window at startup where logging does not behave as expected from the
> command line arguments given. Like, if I redirect log output to a file, the
> first burst of log output would still go to stderr. This may also confuse
> tools which grep the output of a VM.
>
>
> Yes you're right, it's a limitation of UL at the moment. Logging before
> argument parsing means you can only use warning and error level, and can
> only expect to see it on stdout.
>
>
> Additionally, during initialization one may actually want precise control
> of the logging system before arguments are parsed, e.g. in os::init(). We
> have a lot of tracing in the AIX os layer initialization which currently
> goes to nil because it runs before Xlog argument parsing is done.
>
> Both situations could be solved if there were a possibility to specify
> logging options right from the start, e.g. via a file or an environment
> variable, which could be parsed in a static initializer without relying on
> any VM initialization.
>
>
> It's either that or we implement some early logging buffering that saves
> all logging happening before UL initialization and logs it after UL is
> fully initialized. We haven't had the need for that early logging
> previously, but given that you seem to require it, it seems like a
> worthwhile enhancement of UL now.
>
>
Thank you! This would be helpful.

I think that buffering is not a good solution. For one, it requires you
execute each and every log call and buffer the resulting string, because
you do not know yet which of the log calls will be active. This may be cpu
and memory intensive, which especially at startup may hurt.

Also, there is no guarantee the VM even lives long enough to parse the Xlog
arguments to print out the buffered messages. The situations where we use
early logging are often situations where the VM crashes early.

Kind Regards, Thomas



> Thanks,
> Marcus
>
>
> Kind Regards, Thomas
>
>
>
> On Mon, Oct 10, 2016 at 11:20 AM, Marcus Larsson <
> marcus.larsson at oracle.com> wrote:
>
>> Updated webrev after feedback:
>> http://cr.openjdk.java.net/~mlarsson/8146009/webrev.01
>>
>> Incremental:
>> http://cr.openjdk.java.net/~mlarsson/8146009/webrev.00-01
>>
>>
>>
>> On 10/07/2016 04:26 PM, Marcus Larsson wrote:
>>
>>> Hi,
>>>
>>> Making another attempt to fix this issue.
>>>
>>> Summary:
>>> The following patch resolves a problem where the VM would crash during
>>> shutdown due to static log related memory being de-initialized before the
>>> last use of the logging framework. The solution involves parts of the Nifty
>>> Counter idiom [0] to control static initialization and de-initialization of
>>> stdout's and stderr's LogOutputs. Both objects are now allocated using
>>> placement new, and avoids destructor calls during de-initialization. The
>>> LogStreamInitializer makes sure both objects are initialized before first
>>> use.
>>>
>>> Because the LogOutput::Stdout/err pointers could no longer be kept in
>>> LogOutput, I've replaced all usages of them with the new references instead.
>>>
>>> The patch includes a regression test for this issue, contributed by
>>> Michail Chernov.
>>>
>>> Webrev:
>>> http://cr.openjdk.java.net/~mlarsson/8146009/webrev.00
>>>
>>> Issue:
>>> https://bugs.openjdk.java.net/browse/JDK-8146009
>>>
>>> Testing:
>>> JPRT testset hotspot, included test on supported platforms.
>>>
>>> Thanks,
>>> Marcus
>>>
>>> [0] https://en.wikibooks.org/wiki/More_C%2B%2B_Idioms/Nifty_Counter
>>>
>>
>>
>
>