Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Profiler for blocked IpcReceiver::recv() #20132

Merged
merged 1 commit into from Mar 22, 2018
Merged

Conversation

nakul02
Copy link
Contributor

@nakul02 nakul02 commented Feb 27, 2018

Implements feature #19223


  • There are tests for these changes

WIP.
@jdm - this is the new profiler : "Blocked at IPC Receive"
Should I dig through all the calls to ipc::channel and replace them with this profiled IpcReceiver?

screenshot from 2018-02-27 01-35-37


This change is Reviewable

@highfive
Copy link

Thanks for the pull request, and welcome! The Servo team is excited to review your changes, and you should hear from @metajack (or someone else) soon.

@highfive
Copy link

Heads up! This PR modifies the following files:

  • @asajeffrey: components/script/dom/screen.rs
  • @fitzgen: components/profile/time.rs, components/script/dom/screen.rs, components/profile_traits/lib.rs, components/profile_traits/time.rs, components/profile_traits/Cargo.toml and 1 more
  • @KiChjang: components/script/dom/screen.rs

@highfive highfive added the S-awaiting-review There is new code that needs to be reviewed. label Feb 27, 2018
@highfive
Copy link

warning Warning warning

  • These commits modify script code, but no tests are modified. Please consider adding a test!

@jdm
Copy link
Member

jdm commented Feb 27, 2018

Yes, replacing all the users would be really useful!

@nakul02 nakul02 force-pushed the issue_19223 branch 2 times, most recently from 89b183d to 1c16ec2 Compare March 1, 2018 08:34
@nakul02
Copy link
Contributor Author

nakul02 commented Mar 1, 2018

@jdm - I've gone ahead and replaced calls to ipc_channel::ipc::channel to the newly introduced profile_traits::receiver::channel where calls were made to recv in the components/script/dom folder.
Do you want this done project wide for every call to ipc_channel::ipc::channel.
In most other places, there may not be a simple way to get a handle on the ProfilerChan instance.

@nakul02
Copy link
Contributor Author

nakul02 commented Mar 5, 2018

Ping @jdm

@jdm
Copy link
Member

jdm commented Mar 5, 2018

From my point of view, the more we use this API, the more confident we can be that we're actually noticing the biggest offenders. That being said, if you would prefer to merge the changes that you've made so far, we can also continue changing other channels in followup PRs.

@jdm jdm assigned jdm and unassigned metajack Mar 5, 2018
@jdm jdm added S-awaiting-answer Someone asked a question that requires an answer. and removed S-awaiting-review There is new code that needs to be reviewed. labels Mar 5, 2018
@nakul02
Copy link
Contributor Author

nakul02 commented Mar 5, 2018

@jdm - if you have suggestions or guidelines for components that I should check for, I can go in and change those. Otherwise, for now, I'd prefer to merge this.
Does the name profiler_traits::receiver look ok? It is invoked everywhere as receiver::channel.

@jdm
Copy link
Member

jdm commented Mar 8, 2018

@nakul02 What if we used profiler_traits::ipc instead? I think this is a good set of channels to start with, and we can file follow up issues for other instances that make sense, because there are a lot of uses of channels where they are expected to spend a lot of time waiting in recv() and we don't want to report that.

@jdm jdm added S-needs-code-changes Changes have not yet been made that were requested by a reviewer. and removed S-awaiting-answer Someone asked a question that requires an answer. labels Mar 8, 2018
@jdm jdm changed the title [WIP] Profiler for blocked IpcReceiver::recv() Profiler for blocked IpcReceiver::recv() Mar 8, 2018
@jdm
Copy link
Member

jdm commented Mar 8, 2018

Also, I bet we could write a test for this functionality in https://github.com/servo/servo/blob/master/tests/unit/profile/time.rs. Something like:

  1. create a regular channel to mimic the time profiler
  2. create a profiled channel
  3. create a thread that waits for 2 seconds then sends a value with the sender
  4. call recv() in the original thread
  5. call recv() on the time profiler receiver, assert the its reports a realistic value for the time spent waiting on the first recv()
    Does that make sense?

@jdm jdm added the S-needs-tests New tests have been requested by a reviewer. label Mar 8, 2018
@highfive highfive added S-awaiting-review There is new code that needs to be reviewed. and removed S-needs-code-changes Changes have not yet been made that were requested by a reviewer. labels Mar 11, 2018
@nakul02
Copy link
Contributor Author

nakul02 commented Mar 11, 2018

@jdm - I've added a test, but can't figure out why its failing for the life of me. This is the output from its failure:

---- time::channel_profiler_test stdout ----
	thread 'time::channel_profiler_test' panicked at 'called `Result::unwrap()` on an `Err` value: Io(Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" })', libcore/result.rs:916:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
stack backtrace:
   0: std::sys::unix::backtrace::tracing::imp::unwind_backtrace
             at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1: std::sys_common::backtrace::print
             at libstd/sys_common/backtrace.rs:68
             at libstd/sys_common/backtrace.rs:57
   2: std::panicking::default_hook::{{closure}}
             at libstd/panicking.rs:380
   3: std::panicking::default_hook
             at libstd/panicking.rs:390
   4: std::panicking::rust_panic_with_hook
             at libstd/panicking.rs:576
   5: std::panicking::begin_panic
             at libstd/panicking.rs:537
   6: std::panicking::begin_panic_fmt
             at libstd/panicking.rs:521
   7: rust_begin_unwind
             at libstd/panicking.rs:497
   8: core::panicking::panic_fmt
             at libcore/panicking.rs:71
   9: core::result::unwrap_failed
             at /checkout/src/libcore/macros.rs:23
  10: <core::result::Result<T, E>>::unwrap
             at /checkout/src/libcore/result.rs:782
  11: profile_tests::time::channel_profiler_test
             at tests/unit/profile/time.rs:59
  12: <F as alloc::boxed::FnBox<A>>::call_box
             at libtest/lib.rs:1441
             at /checkout/src/libcore/ops/function.rs:223
             at /checkout/src/liballoc/boxed.rs:788
  13: __rust_maybe_catch_panic
             at libpanic_unwind/lib.rs:102


failures:
    time::channel_profiler_test

In this PR, there is a new enum type in the ProfilerMsg enum to be able to ask for a vector of recorded times, given information about a ProfilerBuckets. I've also Serialize-d and Deserialize-d the data that is sent through the channel (or so I hope), but none of it seems to be doing the trick.
Could you please take a look at the code from the last commit to see if anything pops out to you. If it doesn't any suggestion about a simpler way of testing this will help.

Copy link
Member

@jdm jdm left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These changes look great!

assert_eq!(val_profile_receiver, 43);

let (sender, receiver) = ipc::channel().unwrap();
thread::spawn(move || {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No need to create a new thread here.

@jdm
Copy link
Member

jdm commented Mar 11, 2018

Hmm. Unfortunately, this is probably hitting a know bug in ipc-channel that we haven't been able to track down yet. Is there any change if you clone the channel before passing it as an argument?

@nakul02
Copy link
Contributor Author

nakul02 commented Mar 22, 2018

Ping @jdm

@jdm
Copy link
Member

jdm commented Mar 22, 2018

There are many more updates to Cargo.lock than this change requires. Did you run cargo update -a? Could you revert the changes to that file and run ./mach build again instead?

Copy link
Member

@jdm jdm left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Apart from the Cargo.lock changes, this looks great!

@bors-servo
Copy link
Contributor

☔ The latest upstream changes (presumably #20228) made this pull request unmergeable. Please resolve the merge conflicts.

@highfive highfive added the S-needs-rebase There are merge conflict errors. label Mar 22, 2018
@nakul02
Copy link
Contributor Author

nakul02 commented Mar 22, 2018

Thanks @jdm!
I deleted the Cargo.lock and ran mach build -d. That is what caused all those updates to Cargo.lock.
Have fixed that in this latest rebase and commit.

@jdm
Copy link
Member

jdm commented Mar 22, 2018

@bors-servo r+

@bors-servo
Copy link
Contributor

📌 Commit ac40d61 has been approved by jdm

@highfive highfive added S-awaiting-merge The PR is in the process of compiling and running tests on the automated CI. and removed S-awaiting-review There is new code that needs to be reviewed. S-needs-rebase There are merge conflict errors. labels Mar 22, 2018
@bors-servo
Copy link
Contributor

⌛ Testing commit ac40d61 with merge 8660555...

bors-servo pushed a commit that referenced this pull request Mar 22, 2018
Profiler for blocked IpcReceiver::recv()

<!-- Please describe your changes on the following line: -->

Implements feature #19223

---
<!-- Thank you for contributing to Servo! Please replace each `[ ]` by `[X]` when the step is complete, and replace `__` with appropriate data: -->
- [x] `./mach build -d` does not report any errors
- [x] `./mach test-tidy` does not report any errors
- [x] These changes fix #19223 (github issue number if applicable).

<!-- Either: -->
- [x] There are tests for these changes

<!-- Also, please make sure that "Allow edits from maintainers" checkbox is checked, so that we can help you if you get stuck somewhere along the way.-->

<!-- Pull requests that do not address these steps are welcome, but they will require additional verification as part of the review process. -->

WIP.
@jdm - this is the new profiler : "Blocked at IPC Receive"
Should I dig through all the calls to `ipc::channel` and replace them with this profiled `IpcReceiver`?

![screenshot from 2018-02-27 01-35-37](https://user-images.githubusercontent.com/5394361/36721061-b46edea4-1b5e-11e8-91d6-7faba742f237.png)

<!-- Reviewable:start -->
---
This change is [<img src="https://reviewable.io/review_button.svg" height="34" align="absmiddle" alt="Reviewable"/>](https://reviewable.io/reviews/servo/servo/20132)
<!-- Reviewable:end -->
@highfive highfive added S-awaiting-review There is new code that needs to be reviewed. and removed S-awaiting-merge The PR is in the process of compiling and running tests on the automated CI. labels Mar 22, 2018
@jdm
Copy link
Member

jdm commented Mar 22, 2018

@bors-servo r+

@bors-servo
Copy link
Contributor

📌 Commit 7d4e2b1 has been approved by jdm

@highfive highfive added S-awaiting-merge The PR is in the process of compiling and running tests on the automated CI. and removed S-awaiting-review There is new code that needs to be reviewed. labels Mar 22, 2018
@nakul02
Copy link
Contributor Author

nakul02 commented Mar 22, 2018

@jdm - is there a way to just cause Taskcluster to run again?

@bors-servo
Copy link
Contributor

⌛ Testing commit 7d4e2b1 with merge f467bdc...

bors-servo pushed a commit that referenced this pull request Mar 22, 2018
Profiler for blocked IpcReceiver::recv()

<!-- Please describe your changes on the following line: -->

Implements feature #19223

---
<!-- Thank you for contributing to Servo! Please replace each `[ ]` by `[X]` when the step is complete, and replace `__` with appropriate data: -->
- [x] `./mach build -d` does not report any errors
- [x] `./mach test-tidy` does not report any errors
- [x] These changes fix #19223 (github issue number if applicable).

<!-- Either: -->
- [x] There are tests for these changes

<!-- Also, please make sure that "Allow edits from maintainers" checkbox is checked, so that we can help you if you get stuck somewhere along the way.-->

<!-- Pull requests that do not address these steps are welcome, but they will require additional verification as part of the review process. -->

WIP.
@jdm - this is the new profiler : "Blocked at IPC Receive"
Should I dig through all the calls to `ipc::channel` and replace them with this profiled `IpcReceiver`?

![screenshot from 2018-02-27 01-35-37](https://user-images.githubusercontent.com/5394361/36721061-b46edea4-1b5e-11e8-91d6-7faba742f237.png)

<!-- Reviewable:start -->
---
This change is [<img src="https://reviewable.io/review_button.svg" height="34" align="absmiddle" alt="Reviewable"/>](https://reviewable.io/reviews/servo/servo/20132)
<!-- Reviewable:end -->
@bors-servo
Copy link
Contributor

☀️ Test successful - android, arm32, arm64, linux-dev, linux-rel-css, linux-rel-wpt, mac-dev-unit, mac-rel-css1, mac-rel-css2, mac-rel-wpt1, mac-rel-wpt2, mac-rel-wpt3, mac-rel-wpt4, windows-msvc-dev
Approved by: jdm
Pushing f467bdc to master...

@bors-servo bors-servo merged commit 7d4e2b1 into servo:master Mar 22, 2018
@highfive highfive removed the S-awaiting-merge The PR is in the process of compiling and running tests on the automated CI. label Mar 22, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Report time spent in synchronous IPC to the profiler
5 participants