[GHC] #12038: Shutdown interacts badly with requestSync()
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.2.1 Component: Runtime | Version: 7.10.3 System | Keywords: | Operating System: Unknown/Multiple Architecture: | Type of failure: None/Unknown Unknown/Multiple | Test Case: | Blocked By: Blocking: | Related Tickets: Differential Rev(s): | Wiki Page: -------------------------------------+------------------------------------- -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Description changed by simonmar: @@ -0,0 +1,3 @@ + I've been investigating #10860, and the problem goes pretty deep, + so I'm going to record what I know here and come back to fix it + properly later. @@ -2,0 +5,19 @@ + We have this mechanism `requestSync()` for operations that need + to seize control of the whole runtime to do something. It is used by + + * `scheduleDoGC()` + * `setNumCapabilities()` + * `forkProcess()` + + `requestSync()` ensures that only one of these operations wins, + the others will `yieldCapability()` to the winner, before + continuing with their own sync. + + The problem is that this interacts badly with shutdown. Shutdown + might start at any time (initiated by `exitScheduler()`). If it + starts during a sync, then a deadlock is likely: some + capabilities will be already shut down, and cannot be acquired by + `acquireAllCapabilities()`. This happens in #10860. + + Really, shutdown should play the `requestSync()` game too, but + that requires a lot of thought. New description: I've been investigating #10860, and the problem goes pretty deep, so I'm going to record what I know here and come back to fix it properly later. We have this mechanism `requestSync()` for operations that need to seize control of the whole runtime to do something. It is used by * `scheduleDoGC()` * `setNumCapabilities()` * `forkProcess()` `requestSync()` ensures that only one of these operations wins, the others will `yieldCapability()` to the winner, before continuing with their own sync. The problem is that this interacts badly with shutdown. Shutdown might start at any time (initiated by `exitScheduler()`). If it starts during a sync, then a deadlock is likely: some capabilities will be already shut down, and cannot be acquired by `acquireAllCapabilities()`. This happens in #10860. Really, shutdown should play the `requestSync()` game too, but that requires a lot of thought. -- -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:1> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: 10860 Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by Simon Marlow <marlowsd@…>): In [changeset:"cfc5df43a7789832a2789e517d8270650cc31b7f/ghc" cfc5df4/ghc]: {{{ #!CommitTicketReference repository="ghc" revision="cfc5df43a7789832a2789e517d8270650cc31b7f" Fix ASSERT failure and re-enable setnumcapabilities001 The assertion failure was fairly benign, I think, but this fixes it. I've been running the test repeatedly for the last 30 mins and it hasn't triggered. There are other problems exposed by this test (see #12038), but I've worked around those in the test itself for now. I also copied the relevant bits of the parallel library here so that we don't need parallel for the test to run. }}} -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:3> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by Ben Gamari <ben@…>): In [changeset:"2f319609ef0ebffc46aad7f4ad14d5c26750e3ba/ghc" 2f31960/ghc]: {{{ #!CommitTicketReference repository="ghc" revision="2f319609ef0ebffc46aad7f4ad14d5c26750e3ba" Fix ASSERT failure and re-enable setnumcapabilities001 The assertion failure was fairly benign, I think, but this fixes it. I've been running the test repeatedly for the last 30 mins and it hasn't triggered. There are other problems exposed by this test (see #12038), but I've worked around those in the test itself for now. I also copied the relevant bits of the parallel library here so that we don't need parallel for the test to run. (cherry picked from commit cfc5df43a7789832a2789e517d8270650cc31b7f) }}} -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:5> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by bgamari): I've still seen failures of `setnumcapabilities001` since comment:3 was pushed. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:6> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by simonmar): Oh dear. Which ways? What errors? -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:7> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * milestone: 8.2.1 => 8.4.1 Comment:
Oh dear. Which ways? What errors?
Unfortunately it doesn't happen very often; I'll try to paste some output here next time I see this rear its ugly head. Bumping to 8.4. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:8> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by bgamari): Here's one example, {{{ +++ "/tmp/ghctest-8lrukibe/test spaces/./concurrent/should_run/setnumcapabilities001.run/setnumcapabilities001.run.stderr.normalised" 2017-01-05 17:29:54.673595299 -0500 @@ -0,0 +1 @@ +setnumcapabilities001: sendWakeup: invalid argument (Bad file descriptor) }}} -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:9> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by bgamari): I've left the test running for several thousand iterations in the background and have seen the error mentioned in comment:9 pop up a handful of times. On the bright side, this appears to be the only failure mode. It seems what is happening here is that the IO manager is trying to wake- up a manager thread which has already exited. We could simply add an `IORef` to `Control` to indicate that the manager has exited, but it's not clear to me whether this would merely be working around some more sinister root cause. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:10> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by bgamari): I scattered a few `HasCallStacks` about and let it run again and saw the following failure, {{{ setnumcapabilities001: sendWakeup CallStack (from HasCallStack): sendWakeup, called at libraries/base/GHC/Event/TimerManager.hs:205:19 in base:GHC.Event.TimerManager wakeManager, called at libraries/base/GHC/Event/TimerManager.hs:223:7 in base:GHC.Event.TimerManager registerTimeout, called at libraries/base/GHC/Event/Thread.hs:59:10 in base:GHC.Event.Thread: invalid argument (Bad file descriptor) }}} The last frame of the callstack corresponds to the `registerTimeout` in `threadDelay`. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:11> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: patch Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * status: new => patch * differential: => Phab:D2926 Comment: Phab:D2926 is a somewhat questionable patch I put together between builds. I'm a bit unsure as to whether the approach is the sort of thing we want, though. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:12> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: patch Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Comment (by Ben Gamari <ben@…>): In [changeset:"6de7613604216f65fae92d8066a078bf9cd3c088/ghc" 6de76136/ghc]: {{{ #!CommitTicketReference repository="ghc" revision="6de7613604216f65fae92d8066a078bf9cd3c088" event manager: Don't worry if attempt to wake dead manager fails This fixes #12038, where the TimerManager would attempt to wake up a manager that was already dead, resulting in setnumcapabilities001 occassionally failing during shutdown with unexpected output on stderr. I'm frankly still not entirely confident in this solution but perhaps it will help to get a few more eyes on this. My hypothesis is that the TimerManager is racing: thread TimerManager worker ------- -------------------- requests that thread manager shuts down begins to clean up, closing eventfd calls wakeManager, which tries to write to closed eventfd To prevent this `wakeManager` will need to synchronize with the TimerManger worker to ensure that the worker doesn't clean up the `Control` while another thread is trying to send a wakeup. However, this would add a bit of overhead on every timer interaction, which feels rather costly for what is really a problem only at shutdown. Moreover, it seems that the event manager (e.g. `GHC.Event.Manager`) is also afflicted by a similar race. This patch instead simply tries to catch the write failure after it has happened and silence it in the case that the fd has vanished. It feels rather hacky but it seems to work. Test Plan: Run `setnumcapabilities001` repeatedly Reviewers: austin, hvr, simonmar Reviewed By: simonmar Subscribers: thomie Differential Revision: https://phabricator.haskell.org/D2926 GHC Trac Issues: #12038 }}} -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:13> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: closed Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * status: patch => closed * resolution: => fixed * milestone: 8.4.1 => 8.2.1 Comment: I think comment:13 should fix it. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:14> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: closed Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Comment (by Ben Gamari <ben@…>): In [changeset:"d5cd505bc484edee3dbd5d41fb7a27c2e18d528d/ghc" d5cd505b/ghc]: {{{ #!CommitTicketReference repository="ghc" revision="d5cd505bc484edee3dbd5d41fb7a27c2e18d528d" event manager: Don't worry if attempt to wake dead manager fails This fixes #12038, where the TimerManager would attempt to wake up a manager that was already dead, resulting in setnumcapabilities001 occassionally failing during shutdown with unexpected output on stderr. I'm frankly still not entirely confident in this solution but perhaps it will help to get a few more eyes on this. My hypothesis is that the TimerManager is racing: thread TimerManager worker ------- -------------------- requests that thread manager shuts down begins to clean up, closing eventfd calls wakeManager, which tries to write to closed eventfd To prevent this `wakeManager` will need to synchronize with the TimerManger worker to ensure that the worker doesn't clean up the `Control` while another thread is trying to send a wakeup. However, this would add a bit of overhead on every timer interaction, which feels rather costly for what is really a problem only at shutdown. Moreover, it seems that the event manager (e.g. `GHC.Event.Manager`) is also afflicted by a similar race. This patch instead simply tries to catch the write failure after it has happened and silence it in the case that the fd has vanished. It feels rather hacky but it seems to work. Test Plan: Run `setnumcapabilities001` repeatedly Reviewers: hvr, austin, simonmar Subscribers: thomie Differential Revision: https://phabricator.haskell.org/D2957 GHC Trac Issues: #12038 }}} -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:15> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: Type: bug | Status: new Priority: normal | Milestone: 8.2.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Changes (by simonmar): * status: closed => new * resolution: fixed => Comment: @bgamari: I think the original issue that this ticket describes still exists. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:16> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: #5553 | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Changes (by dfeuer): * related: => #5553 Comment: The fix for this ''appears'' to have fixed #5553 as well. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:18> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.4.1 Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: #5553 | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Comment (by dfeuer): Well, I guess not the ''fix'' for this, but Ben's patch. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:19> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
#12038: Shutdown interacts badly with requestSync() -------------------------------------+------------------------------------- Reporter: simonmar | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: Component: Runtime System | Version: 7.10.3 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: | Unknown/Multiple Type of failure: None/Unknown | Test Case: Blocked By: | Blocking: Related Tickets: #5553 | Differential Rev(s): Phab:D2926 Wiki Page: | -------------------------------------+------------------------------------- Changes (by bgamari): * milestone: 8.6.1 => Comment: Demilestoning due to lack of progress. -- Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/12038#comment:21> GHC <http://www.haskell.org/ghc/> The Glasgow Haskell Compiler
participants (1)
-
GHC