Fix race condition on ManifestService initialization.

Fix race condition on ManifestService initialization.

SyncMessageFilter::Send() returns false immediately, if the IPC connection
is not yet established. As connecting is done asynchronously, there is
no guarantee that the connection is established on the first Send() invocation.
By this CL, Send() blocks the caller thread if the connection is not yet
established.
Note that currently the ratio should be probably low, because there are some
more initialization steps between the ManifestService creation and the first
Send() invocation. We're switching to changing the initialization procedure,
and then this race would be hit more easily.

TEST=Ran browser_tests --gtest_filter=*NonSfi*:*NonSFI* locally, and trybots. Also, locally modified the code to delay OnFilterAdded with and without this CL, and made sure this CL works well.
BUG=333950
CQ_EXTRA_TRYBOTS=tryserver.chromium:linux_rel_precise32

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=277840

[hidehiko, 2014-06-12 10:17:26]

Hi Mark, Justin,

During the investigation of SRPC -> IPC switching, I found a race issue. Could
you take a look?

Thank you for your review in advance,
- hidehiko

[teravest, 2014-06-12 14:29:39]

Hidehiko,

Reading through the IPC code, I don't see how this is the case:
"SyncMessageFilter::Send() returns false immediately, if the IPC
connection is not yet established"

io_loop_ should be set up properly from
SyncMessageFilter::OnFilterAdded... what causes send to return false
instead of blocking for the channel to connect?

On Thu, Jun 12, 2014 at 4:17 AM,  <hidehiko@chromium.org> wrote:
> Reviewers: Mark Seaborn, teravest,
>
> Message:
> Hi Mark, Justin,
>
> During the investigation of SRPC -> IPC switching, I found a race issue.
> Could
> you take a look?
>
> Thank you for your review in advance,
> - hidehiko
>
> Description:
> Fix race condition on ManifestService initialization.
>
> SyncMessageFilter::Send() returns false immediately, if the IPC connection
> is not yet established. As connecting is done asynchronously, there is
> no guarantee that the connection is established on the first Send()
> invocation.
> By this CL, Send() blocks the caller thread if the connection is not yet
> established.
> Note that currently the ratio should be probably low, because there are some
> more initialization steps between the ManifestService creation and the first
> Send() invocation. We're switching to changing the initialization procedure,
> and then this race would be hit more easily.
>
> TEST=Ran browser_tests --gtest_filter=*NonSfi*:*NonSFI* locally, and
> trybots.
> BUG=333950
>
> Please review this at https://codereview.chromium.org/334593004/
>
> SVN Base: svn://svn.chromium.org/chrome/trunk/src
>
> Affected files (+42, -1 lines):
>   M ppapi/nacl_irt/manifest_service.cc
>
>
> Index: ppapi/nacl_irt/manifest_service.cc
> diff --git a/ppapi/nacl_irt/manifest_service.cc
> b/ppapi/nacl_irt/manifest_service.cc
> index
>
85b7fae2c960c9ca5ca156abf3213b9deed1524a..4ea922dc39bfb4d23c16adfa21de97e89f2fc88b
> 100644
> --- a/ppapi/nacl_irt/manifest_service.cc
> +++ b/ppapi/nacl_irt/manifest_service.cc
> @@ -17,11 +17,52 @@ namespace ppapi {
>
>  const char kFilePrefix[] = "files/";
>
> +// IPC channel is asynchronously set up. So, the plugin may be try to send
> +// a OpenResource message to the host before the connection is established.
> +// In such a case, it is necessary to wait for the set up completion.
> +class ManifestMessageFilter : public IPC::SyncMessageFilter {
> + public:
> +  ManifestMessageFilter(base::WaitableEvent* shutdown_event)
> +      : SyncMessageFilter(shutdown_event),
> +        connected_event_(true, false) {  // Reset manually, and init by
> false.
> +  }
> +
> +  virtual bool Send(IPC::Message* message) OVERRIDE {
> +    // Wait until set up is actually done.
> +    connected_event_.Wait();
> +    return SyncMessageFilter::Send(message);
> +  }
> +
> +  // When set up is done, OnFilterAdded is called on IO thread. Unblocks
> the
> +  // Send().
> +  virtual void OnFilterAdded(IPC::Channel* channel) OVERRIDE {
> +    SyncMessageFilter::OnFilterAdded(channel);
> +    connected_event_.Signal();
> +  }
> +
> +  // If an error is found, unblocks the Send(), too, to return an error.
> +  virtual void OnChannelError() OVERRIDE {
> +    SyncMessageFilter::OnChannelError();
> +    connected_event_.Signal();
> +  }
> +
> +  // Similar to OnChannelError, unblocks the Send() on the channel closing.
> +  virtual void OnChannelClosing() OVERRIDE {
> +    SyncMessageFilter::OnChannelClosing();
> +    connected_event_.Signal();
> +  }
> +
> + private:
> +  base::WaitableEvent connected_event_;
> +
> +  DISALLOW_COPY_AND_ASSIGN(ManifestMessageFilter);
> +};
> +
>  ManifestService::ManifestService(
>      const IPC::ChannelHandle& handle,
>      scoped_refptr<base::MessageLoopProxy> io_message_loop,
>      base::WaitableEvent* shutdown_event) {
> -  filter_ = new IPC::SyncMessageFilter(shutdown_event);
> +  filter_ = new ManifestMessageFilter(shutdown_event);
>    channel_ = IPC::ChannelProxy::Create(handle,
>                                         IPC::Channel::MODE_SERVER,
>                                         NULL,  // Listener
>
>

To unsubscribe from this group and stop receiving emails from it, send an email
to chromium-reviews+unsubscribe@chromium.org.

[hidehiko, 2014-06-12 14:41:27]

Hi,

On 2014/06/12 14:29:39, teravest wrote:
> Hidehiko,
> 
> Reading through the IPC code, I don't see how this is the case:
> "SyncMessageFilter::Send() returns false immediately, if the IPC
> connection is not yet established"
> 
> io_loop_ should be set up properly from
> SyncMessageFilter::OnFilterAdded... what causes send to return false
> instead of blocking for the channel to connect?

io_loop_ is set in OnFilterAdded, but it is called when the connection is
established.
So, "until then", Send() returns false immediately.

Thanks,
- hidehiko


> 
> On Thu, Jun 12, 2014 at 4:17 AM,  <mailto:hidehiko@chromium.org> wrote:
> > Reviewers: Mark Seaborn, teravest,
> >
> > Message:
> > Hi Mark, Justin,
> >
> > During the investigation of SRPC -> IPC switching, I found a race issue.
> > Could
> > you take a look?
> >
> > Thank you for your review in advance,
> > - hidehiko
> >
> > Description:
> > Fix race condition on ManifestService initialization.
> >
> > SyncMessageFilter::Send() returns false immediately, if the IPC connection
> > is not yet established. As connecting is done asynchronously, there is
> > no guarantee that the connection is established on the first Send()
> > invocation.
> > By this CL, Send() blocks the caller thread if the connection is not yet
> > established.
> > Note that currently the ratio should be probably low, because there are some
> > more initialization steps between the ManifestService creation and the first
> > Send() invocation. We're switching to changing the initialization procedure,
> > and then this race would be hit more easily.
> >
> > TEST=Ran browser_tests --gtest_filter=*NonSfi*:*NonSFI* locally, and
> > trybots.
> > BUG=333950
> >
> > Please review this at https://codereview.chromium.org/334593004/
> >
> > SVN Base: svn://svn.chromium.org/chrome/trunk/src
> >
> > Affected files (+42, -1 lines):
> >   M ppapi/nacl_irt/manifest_service.cc
> >
> >
> > Index: ppapi/nacl_irt/manifest_service.cc
> > diff --git a/ppapi/nacl_irt/manifest_service.cc
> > b/ppapi/nacl_irt/manifest_service.cc
> > index
> >
>
85b7fae2c960c9ca5ca156abf3213b9deed1524a..4ea922dc39bfb4d23c16adfa21de97e89f2fc88b
> > 100644
> > --- a/ppapi/nacl_irt/manifest_service.cc
> > +++ b/ppapi/nacl_irt/manifest_service.cc
> > @@ -17,11 +17,52 @@ namespace ppapi {
> >
> >  const char kFilePrefix[] = "files/";
> >
> > +// IPC channel is asynchronously set up. So, the plugin may be try to send
> > +// a OpenResource message to the host before the connection is established.
> > +// In such a case, it is necessary to wait for the set up completion.
> > +class ManifestMessageFilter : public IPC::SyncMessageFilter {
> > + public:
> > +  ManifestMessageFilter(base::WaitableEvent* shutdown_event)
> > +      : SyncMessageFilter(shutdown_event),
> > +        connected_event_(true, false) {  // Reset manually, and init by
> > false.
> > +  }
> > +
> > +  virtual bool Send(IPC::Message* message) OVERRIDE {
> > +    // Wait until set up is actually done.
> > +    connected_event_.Wait();
> > +    return SyncMessageFilter::Send(message);
> > +  }
> > +
> > +  // When set up is done, OnFilterAdded is called on IO thread. Unblocks
> > the
> > +  // Send().
> > +  virtual void OnFilterAdded(IPC::Channel* channel) OVERRIDE {
> > +    SyncMessageFilter::OnFilterAdded(channel);
> > +    connected_event_.Signal();
> > +  }
> > +
> > +  // If an error is found, unblocks the Send(), too, to return an error.
> > +  virtual void OnChannelError() OVERRIDE {
> > +    SyncMessageFilter::OnChannelError();
> > +    connected_event_.Signal();
> > +  }
> > +
> > +  // Similar to OnChannelError, unblocks the Send() on the channel closing.
> > +  virtual void OnChannelClosing() OVERRIDE {
> > +    SyncMessageFilter::OnChannelClosing();
> > +    connected_event_.Signal();
> > +  }
> > +
> > + private:
> > +  base::WaitableEvent connected_event_;
> > +
> > +  DISALLOW_COPY_AND_ASSIGN(ManifestMessageFilter);
> > +};
> > +
> >  ManifestService::ManifestService(
> >      const IPC::ChannelHandle& handle,
> >      scoped_refptr<base::MessageLoopProxy> io_message_loop,
> >      base::WaitableEvent* shutdown_event) {
> > -  filter_ = new IPC::SyncMessageFilter(shutdown_event);
> > +  filter_ = new ManifestMessageFilter(shutdown_event);
> >    channel_ = IPC::ChannelProxy::Create(handle,
> >                                         IPC::Channel::MODE_SERVER,
> >                                         NULL,  // Listener
> >
> >
> 
> To unsubscribe from this group and stop receiving emails from it, send an
email
> to mailto:chromium-reviews+unsubscribe@chromium.org.

[teravest, 2014-06-12 14:42:50]

lgtm

OK, Thanks for explaining.

[Mark Seaborn, 2014-06-13 00:34:35]

Is there a place where you can add a sleep() call that makes the race condition
reliably reproducible?  If so, maybe you could say that in the TEST= field?

https://codereview.chromium.org/334593004/diff/1/ppapi/nacl_irt/manifest_serv...
File ppapi/nacl_irt/manifest_service.cc (right):

https://codereview.chromium.org/334593004/diff/1/ppapi/nacl_irt/manifest_serv...
ppapi/nacl_irt/manifest_service.cc:20: // IPC channel is asynchronously set up.
So, the plugin may be try to send
Nit: "plugin" is ambiguous.  Maybe say "NaCl process"?

https://codereview.chromium.org/334593004/diff/1/ppapi/nacl_irt/manifest_serv...
ppapi/nacl_irt/manifest_service.cc:27: connected_event_(true, false) {  // Reset
manually, and init by false.
Nit: "init with" rather than "by"?

But if this is intended to comment the arguments, maybe it would be clearer to
write something like this:

connected_event_(/* manual_reset= */ true, /* initially_signaled= */ false);

[hidehiko, 2014-06-13 04:37:10]

Thank you for review. PTAL.

> Is there a place where you can add a sleep() call that makes the race
condition
reliably reproducible?  If so, maybe you could say that in the TEST= field?

For that purpose, we need to add sleep in very very low layer so it is not a
light way... Instead, I delayed the OnFilterAdded a bit to emulate the situation
easily. They should have same meaning for the NaCl plugin's point of view. Added
TEST statement.

https://codereview.chromium.org/334593004/diff/1/ppapi/nacl_irt/manifest_serv...
File ppapi/nacl_irt/manifest_service.cc (right):

https://codereview.chromium.org/334593004/diff/1/ppapi/nacl_irt/manifest_serv...
ppapi/nacl_irt/manifest_service.cc:20: // IPC channel is asynchronously set up.
So, the plugin may be try to send
On 2014/06/13 00:34:35, Mark Seaborn wrote:
> Nit: "plugin" is ambiguous.  Maybe say "NaCl process"?

Done.

https://codereview.chromium.org/334593004/diff/1/ppapi/nacl_irt/manifest_serv...
ppapi/nacl_irt/manifest_service.cc:27: connected_event_(true, false) {  // Reset
manually, and init by false.
On 2014/06/13 00:34:35, Mark Seaborn wrote:
> Nit: "init with" rather than "by"?
> 
> But if this is intended to comment the arguments, maybe it would be clearer to
> write something like this:
> 
> connected_event_(/* manual_reset= */ true, /* initially_signaled= */ false);

Changed the style to one which seems to be used in chrome repository (by grep).

[Mark Seaborn, 2014-06-13 16:40:48]

On 2014/06/13 04:37:10, hidehiko wrote:
> Thank you for review. PTAL.

Rubber-stamp LGTM (since Justin reviewed this and I didn't look into the details
of the race condition closely).  I didn't mean for you to wait for me. :-)

https://codereview.chromium.org/334593004/diff/60001/ppapi/nacl_irt/manifest_...
File ppapi/nacl_irt/manifest_service.cc (right):

https://codereview.chromium.org/334593004/diff/60001/ppapi/nacl_irt/manifest_...
ppapi/nacl_irt/manifest_service.cc:20: // IPC channel is asynchronously set up.
So, the NaCl process may be try to
Nit: "may try" (I missed this before)

[hidehiko, 2014-06-16 03:39:44]

Thank you for review. Submitting.

https://codereview.chromium.org/334593004/diff/60001/ppapi/nacl_irt/manifest_...
File ppapi/nacl_irt/manifest_service.cc (right):

https://codereview.chromium.org/334593004/diff/60001/ppapi/nacl_irt/manifest_...
ppapi/nacl_irt/manifest_service.cc:20: // IPC channel is asynchronously set up.
So, the NaCl process may be try to
On 2014/06/13 16:40:48, Mark Seaborn wrote:
> Nit: "may try" (I missed this before)

Done.

https://codereview.chromium.org/334593004/diff/80001/ppapi/nacl_irt/manifest_...
File ppapi/nacl_irt/manifest_service.cc (right):

https://codereview.chromium.org/334593004/diff/80001/ppapi/nacl_irt/manifest_...
ppapi/nacl_irt/manifest_service.cc:40: virtual void OnFilterAdded(IPC::Sender*
sender) OVERRIDE {
FYI: Rebasing needs to change the arg's type.
cf) https://codereview.chromium.org/324143002

[hidehiko, 2014-06-16 03:39:57]

The CQ bit was checked by hidehiko@chromium.org

[commit-bot: I haz the power, 2014-06-16 03:40:16]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/hidehiko@chromium.org/334593004/100001

[commit-bot: I haz the power, 2014-06-16 07:31:32]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2014-06-16 07:31:33]

Try jobs failed on following builders:
  linux_rel_precise32 on tryserver.chromium
(http://build.chromium.org/p/tryserver.chromium/builders/linux_rel_precise32/b...)

[hidehiko, 2014-06-16 07:36:31]

The CQ bit was checked by hidehiko@chromium.org

[commit-bot: I haz the power, 2014-06-16 07:37:24]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/hidehiko@chromium.org/334593004/100001

[commit-bot: I haz the power, 2014-06-16 07:39:11]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2014-06-16 07:39:12]

Try jobs failed on following builders:
  linux_rel_precise32 on tryserver.chromium
(http://build.chromium.org/p/tryserver.chromium/builders/linux_rel_precise32/b...)

[hidehiko, 2014-06-16 16:34:27]

The CQ bit was checked by hidehiko@chromium.org

[commit-bot: I haz the power, 2014-06-16 16:35:33]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/hidehiko@chromium.org/334593004/100001

[commit-bot: I haz the power, 2014-06-16 16:38:13]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2014-06-16 16:38:14]

Try jobs failed on following builders:
  linux_rel_precise32 on tryserver.chromium
(http://build.chromium.org/p/tryserver.chromium/builders/linux_rel_precise32/b...)

[hidehiko, 2014-06-17 17:56:26]

The CQ bit was checked by hidehiko@chromium.org

[commit-bot: I haz the power, 2014-06-17 17:58:17]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/hidehiko@chromium.org/334593004/100001

[commit-bot: I haz the power, 2014-06-17 20:06:34]

Change committed as 277840