JEP 158

[Kirk Pepperdine]

> 
>>> 
>>> I understand what you want and I see that the logging level won't help us get there. I don't agree that the logging we have today can't fit nicely into a hierarchical scheme though, it just needs to be more fine grained to achieve what you want.
>> 
>> I think to do this you have to assume structure which may or may not apply to everyone. In this case I'd rather drop the assumption and work towards a solution that doesn't prevent but enables.
> 
> Well, the structure is there in the VM. We can't really take that away. Tenuring is and will most likely always be part of the GC.
> I'm not sure I understand how the structure of the VM will prevent people from using the logs efficiently.

I'm not sure that I understand what you don't understand here ;-)

> 
>> 
>>> 
>>> We can be pretty generous with modules and in principal have one module for each verbose flag that exists today. Personally I don't think that is a good idea, but it certainly is possible. I would rather like to propose a different solution.
>>> 
>>> How about we have a gc module that can be filtered based on different sub modules. The sub modules could be fairly close to the existing verbose flags that exists today if that turns out to be a good way to divide information. It could look like this
>>> 
>>> -Xverbose:gc=info,gc.tenuring=debug
>>> 
>>> to set regular gc verbose to info level (I would say that is close to PrintGC) and turn on more detailed logging for tenuring. Or
>>> 
>>> -Xverbose:gc.tenuring
>> 
>> I predicted that you'd come back with the way to shoehorn the problem into leveling. I don't really see this as an appropriate solution as in this case because tenuring distribution is only one aspect of logging. Maybe that's what I we need, a new term for logging.. I'll call this Aspect Oriented Logging which I see as being completely different than hierarchical logging which is the quagmire we've been stuck in for far too long.
> 
> What I did here was to extend the module system. That is completely separate from the logging levels.

Sorry but your first response suggests logging levels.

> 
>>> that could be equal to what that flag prints today. Let's see what the serviceability team thinks since they are the ones who will actually implement this in the end.
>>> 
>>> Another solution that I don't really like but guess is easier to implement is to add the current verbose flag to the actual message so that the logs can be filtered based on that. But this will clutter the messages and we would still have the problem to decide on which level things should get logged.
>> 
>> IMHO, we don't have a good taxonomy for logging categories and instead of over-reaching and forcing one on everybody, why not come to a specification that would allow groups to define their own. So again, I ask the question, what would the specification look like with levels taken out.
> 
> Well, if you remove the levels from the current specification you'd be left with just the modules. That would work I guess, but it would be a slightly less powerful logging framework. Let me describe what I think that you want to achieve. Please correct me if I'm wrong.

I think you'd be left with a more powerful logging system. More assumption == more constraints == less adaptive to things you may need to do. In this case I don't think you need to make that extra assumption. Just my opinion.


> 
> You'd like to specify that you are for instance interested in tenuring. The logs that you are interested in in this case should contain information about heap, eden and survivor sizes. They should contain tenuring threshold and information about objects that has been tenured like number of objects and their sizes etc. And maybe some more stuff.
> 
> A different aspect could be that you are interested in fragmentation. Again you'd like information about heap sizes, free memory in different areas, sizes of the individual free areas and their count. Maybe some timestamps that could tell you how long ago an area was compacted etc.
> 
> Obviously aspects could cut through other parts of the VM as well, not just GC logging. Is this roughly what you are looking for?

Yes, this sounds like were heading on the right track.

> 
> To be able to achieve this we would have to divide all verbose data into different categories and have a mechanism to based on the aspect select the correct categories for output.

Well, this is how the current set of flags work.

> 
> I would say that this is exactly what we can achieve with the proposed logging framework. The only difference is that the user is able to pick and choose exactly what information to include instead of just having an aspect that will give a predefined set of logging events. We could easily provide a set of predefined config files that selects different logging modules based on the desired aspect.

Indeed!

> 
> If we add the levels into this we could also specify that some aspect would like to provide very detailed information about something while a different aspect could satisfy for a less detailed overview of that particular something.

Sure but you could also leave that up to the implementor by giving the facility to easily combine aspects.

> 
> If this was not at all what you wanted please let me know. Examples of what you'd like to see would be much appreciated.

You can curse the current flag system but there is some goodness in there so I don't think we should throw out the whole thing. Flags become additive. I don't necessarily need to set one flag to see details about another aspect of GC. I can turn on PrintApplicationStoppedTime and I can turn on PrintHeapAtGC independently of each other. This part isn't all that bad. That there is nothing you can do about the output from PrintCompilation is a PITA. I want to get that stuff into a file. And, it all needs to be better formatted so that it can more easily be tooled but I think that is the responsibility those generating the data.

This is also slightly beyond the scope of this specification but right now the GC logs are corrupted when using the CMS collector. It logs in the middle of the young gen collectors records (fortunately at very predictable time). I wouldn't be happy with something the async log4j appender showing up here because of the number of times I've had to tell clients that the synchronization bottleneck they were experiencing was a result of the appender. That said, I'm not so happy about log corruption. We need a lock free thread safe way to write logs down to disk. I would say that a sensible solution is the one taken by the HotSpot guys when they decided to push data out on a file per thread (combined at VM shutdown). Ok, not without it's problems but I run into those problems far less frequently than I do logging bottlenecks.

Regards,
Kirk