Migrate logging infrastructure Isolate->Thread

Migrate logging infrastructure Isolate->Thread

This enables thread-safe logging (e.g., ISL_Print, which will soon be renamed to THR_Print), which is needed for concurrent
marking (DetachCode) and compilation.

Make finalization of GC marking tasks concurrent, now that it's thread-safe.

BUG=
R=iposva@google.com

Committed: https://github.com/dart-lang/sdk/commit/a1bc52730665aee36b3ba1dc72ab35f6e4fc44aa

[koda, 2015-09-08 16:21:38]

koda@google.com changed reviewers:
+ iposva@google.com

[koda, 2015-09-08 16:32:46]

Updated with addressing the related TODO in gc_marker (concurrent finalization
of marking tasks).

Let me know if you prefer I rename ISL_Print to THR_Print already in this CL.

[Ivan Posva, 2015-09-08 21:22:22]

First round of comments.

-Ivan

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/isolate.cc
File runtime/vm/isolate.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/isolate.cc#n...
runtime/vm/isolate.cc:702: log_(new class Log()),
Why does the isolate still carry around a log_ after this change?

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/isolate.cc#n...
runtime/vm/isolate.cc:910: bool Isolate::ShouldLog() const {
We might want to move this functionality into the Log class instead.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc
File runtime/vm/log.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:78: buffer_.TruncateTo(cursor);
As far as I can tell this is broken as the string in the buffer is not '\0'
terminated after the truncation.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:124: CommonConstructor();
How about changing CommonConstructor() to Initialize(Log*) and use it for both
constructors to also initialize the fields?

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h
File runtime/vm/log.h (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h#newcode17
runtime/vm/log.h:17: // TODO(koda): Rename ISL_* -> THR_*.
Why not do the rename right now?

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h#newcode79
runtime/vm/log.h:79: explicit LogBlock(Thread* thread);
Is there a particular reason to have this constructor in the .cc file, while the
other is inlined?

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h#newcode82
runtime/vm/log.h:82: CommonDestructor();
ditto.

Please move to .cc file and remove the unnecessary CommonDestructor().

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/thread.cc
File runtime/vm/thread.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/thread.cc#ne...
runtime/vm/thread.cc:115: log_(new class Log()) {
I do not like the fact that we allocate this bottom Log object which collect all
log events unless they are flushed. I'd prefer if we had this at NULL until
somebody setup logging for a thread.

Why not new Log()? If we move the logic for filtering into the Log class then we
have a simple accessor for log() and do not fall into this problem.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/thread.cc#ne...
runtime/vm/thread.cc:315: if (isolate_ != NULL && isolate_->ShouldLog()) {
This logic is now distributed across three different part. Please investigate
how to move this into the Log class only.

[koda, 2015-09-09 00:26:57]

Addressed comments, PTAL.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/isolate.cc
File runtime/vm/isolate.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/isolate.cc#n...
runtime/vm/isolate.cc:702: log_(new class Log()),
On 2015/09/08 21:22:21, Ivan Posva wrote:
> Why does the isolate still carry around a log_ after this change?

Removed.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/isolate.cc#n...
runtime/vm/isolate.cc:910: bool Isolate::ShouldLog() const {
On 2015/09/08 21:22:21, Ivan Posva wrote:
> We might want to move this functionality into the Log class instead.

Done.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc
File runtime/vm/log.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:78: buffer_.TruncateTo(cursor);
On 2015/09/08 21:22:21, Ivan Posva wrote:
> As far as I can tell this is broken as the string in the buffer is not '\0'
> terminated after the truncation.

The design does *not* assume buffer_ is '\0'-terminated (see comment in
Log::VPrint). The '\0' is only added when printing/flushing.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:124: CommonConstructor();
On 2015/09/08 21:22:21, Ivan Posva wrote:
> How about changing CommonConstructor() to Initialize(Log*) and use it for both
> constructors to also initialize the fields?

Done (although it prevents the cursor_ field from being declared const).

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h
File runtime/vm/log.h (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h#newcode17
runtime/vm/log.h:17: // TODO(koda): Rename ISL_* -> THR_*.
On 2015/09/08 21:22:22, Ivan Posva wrote:
> Why not do the rename right now?

Done.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h#newcode79
runtime/vm/log.h:79: explicit LogBlock(Thread* thread);
On 2015/09/08 21:22:22, Ivan Posva wrote:
> Is there a particular reason to have this constructor in the .cc file, while
the
> other is inlined?

Done.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.h#newcode82
runtime/vm/log.h:82: CommonDestructor();
On 2015/09/08 21:22:22, Ivan Posva wrote:
> ditto.
> 
> Please move to .cc file and remove the unnecessary CommonDestructor().

Done.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/thread.cc
File runtime/vm/thread.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/thread.cc#ne...
runtime/vm/thread.cc:115: log_(new class Log()) {
On 2015/09/08 21:22:22, Ivan Posva wrote:
> I do not like the fact that we allocate this bottom Log object which collect
all
> log events unless they are flushed. I'd prefer if we had this at NULL until
> somebody setup logging for a thread.
> 
> Why not new Log()? If we move the logic for filtering into the Log class then
we
> have a simple accessor for log() and do not fall into this problem.

The log is flushed by Print or by the destructor of a LogBlock. Added ASSERT to
~Log.

Regarding moving all filtering into Log, see comment below.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/thread.cc#ne...
runtime/vm/thread.cc:315: if (isolate_ != NULL && isolate_->ShouldLog()) {
On 2015/09/08 21:22:22, Ivan Posva wrote:
> This logic is now distributed across three different part. Please investigate
> how to move this into the Log class only.

Moved the flag checking logic from Isolate to Log.

To have everything in Log, we would update Thread::log_ whenever we enter/exit
an isolate, and only check the filter in a factory method
Log::NewLogForIsolate(Isolate*).

However, to ensure everyone's on the same page, I think we should first discuss
the value/future of log filtering with John when he returns, so I'll leave this
as is with the suggestion as a TODO for now, OK?

[Ivan Posva, 2015-09-09 19:56:24]

LGTM with discussed change.

-Ivan

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc
File runtime/vm/log.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:78: buffer_.TruncateTo(cursor);
On 2015/09/09 00:26:57, koda wrote:
> On 2015/09/08 21:22:21, Ivan Posva wrote:
> > As far as I can tell this is broken as the string in the buffer is not '\0'
> > terminated after the truncation.
> 
> The design does *not* assume buffer_ is '\0'-terminated (see comment in
> Log::VPrint). The '\0' is only added when printing/flushing.
> 

Thanks for pointing that out. Sneaky!

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:124: CommonConstructor();
On 2015/09/09 00:26:57, koda wrote:
> On 2015/09/08 21:22:21, Ivan Posva wrote:
> > How about changing CommonConstructor() to Initialize(Log*) and use it for
both
> > constructors to also initialize the fields?
> 
> Done (although it prevents the cursor_ field from being declared const).

Actually, I am fine with duplicating the code and having both log_ and cursor_
be const instead.

https://codereview.chromium.org/1314673008/diff/60001/runtime/vm/thread.cc
File runtime/vm/thread.cc (right):

https://codereview.chromium.org/1314673008/diff/60001/runtime/vm/thread.cc#ne...
runtime/vm/thread.cc:314: class Log* Thread::Log() const {
As discussed we can probably move this into a Log::Current() and a simple
accessor here.

[koda, 2015-09-09 22:22:57]

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc
File runtime/vm/log.cc (right):

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:78: buffer_.TruncateTo(cursor);
On 2015/09/09 19:56:24, Ivan Posva wrote:
> On 2015/09/09 00:26:57, koda wrote:
> > On 2015/09/08 21:22:21, Ivan Posva wrote:
> > > As far as I can tell this is broken as the string in the buffer is not
'\0'
> > > terminated after the truncation.
> > 
> > The design does *not* assume buffer_ is '\0'-terminated (see comment in
> > Log::VPrint). The '\0' is only added when printing/flushing.
> > 
> 
> Thanks for pointing that out. Sneaky!

Acknowledged.

https://codereview.chromium.org/1314673008/diff/40001/runtime/vm/log.cc#newco...
runtime/vm/log.cc:124: CommonConstructor();
On 2015/09/09 19:56:24, Ivan Posva wrote:
> On 2015/09/09 00:26:57, koda wrote:
> > On 2015/09/08 21:22:21, Ivan Posva wrote:
> > > How about changing CommonConstructor() to Initialize(Log*) and use it for
> both
> > > constructors to also initialize the fields?
> > 
> > Done (although it prevents the cursor_ field from being declared const).
> 
> Actually, I am fine with duplicating the code and having both log_ and cursor_
> be const instead.

Done.

https://codereview.chromium.org/1314673008/diff/60001/runtime/vm/thread.cc
File runtime/vm/thread.cc (right):

https://codereview.chromium.org/1314673008/diff/60001/runtime/vm/thread.cc#ne...
runtime/vm/thread.cc:314: class Log* Thread::Log() const {
On 2015/09/09 19:56:24, Ivan Posva wrote:
> As discussed we can probably move this into a Log::Current() and a simple
> accessor here.

Done.

[koda, 2015-09-09 22:30:42]

Committed patchset #6 (id:100001) manually as
a1bc52730665aee36b3ba1dc72ab35f6e4fc44aa (presubmit successful).

[Ivan Posva, 2015-09-10 15:40:32]

Thanks for updating.

Just noticed a cosmetic issue, which can easily be fixed later...

-Ivan

https://codereview.chromium.org/1314673008/diff/100001/runtime/vm/thread.cc
File runtime/vm/thread.cc (right):

https://codereview.chromium.org/1314673008/diff/100001/runtime/vm/thread.cc#n...
runtime/vm/thread.cc:115: log_(new class Log()) {
Now we can drop the "class" here.