#15143: Passing an IO value through several functions results in program hanging. -------------------------------------+------------------------------------- Reporter: Burtannia | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.6.1 Component: Compiler | Version: 8.4.2 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Runtime | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Changes (by Burtannia): * Attachment "Bug.hs" added. Data structure and functions to demonstrate the bug. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/15143 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#15143: Passing an IO value through several functions results in program hanging. -------------------------------------+------------------------------------- Reporter: Burtannia | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.6.1 Component: Compiler | Version: 8.4.2 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Runtime | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Description changed by Burtannia: Old description:

I came across this rather interesting bug while writing my dissertation.

The following function takes an IO Obs and if it is an observable of time (ObsTime) it increments the contained Int. Otherwise it leaves it unchanged:

{{{#!hs incTime :: IO Obs -> IO Obs incTime o = do obs <- o case obs of ObsTime t -> return $ ObsTime (t+1) _ -> o }}}

The case for ObsTime works as expected however, the wildcard case gets progressively slower the more times a value is passed through. At 30 iterations I waited 10 seconds before aborting execution, the function had still not returned.

This issue does not occur with the following change to the wildcard case: {{{#!hs _ -> return obs }}}

This issue occurs both in GHCi and after compiling with GHC.

It might also be worth mentioning that I've had the issue on Ubuntu (GHC 8.4.2 & 7.10.3) and Windows 7 (GHC 8.0.2). So it doesn't seem to be OS specific or caused by a recent change to GHC.

I have attached a file with the necessary code to demonstrate the issue.

New description: I came across this rather interesting bug while writing my dissertation. The following function takes an IO Obs and if it is an observable of time (ObsTime) it increments the contained Int. Otherwise it leaves it unchanged: {{{#!hs incTime :: IO Obs -> IO Obs incTime o = do obs <- o case obs of ObsTime t -> return $ ObsTime (t+1) _ -> o }}} The case for ObsTime works as expected however, the wildcard case gets progressively slower the more times a value is passed through. At 30 iterations I waited 10 seconds before aborting execution, the function had still not returned. This issue does not occur with the following change to the wildcard case: {{{#!hs _ -> return obs }}} This issue occurs both in GHCi and after compiling with GHC (with and without -O2). It might also be worth mentioning that I've had the issue on Ubuntu (GHC 8.4.2 & 7.10.3) and Windows 7 (GHC 8.0.2). So it doesn't seem to be OS specific or caused by a recent change to GHC. I have attached a file with the necessary code to demonstrate the issue. -- -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/15143#comment:2 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#15143: Passing an IO value through several functions results in program hanging. -------------------------------------+------------------------------------- Reporter: Burtannia | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.6.1 Component: Compiler | Version: 8.4.2 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Runtime | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by osa1): I made the slow program parametric on number of iterations. Seems like an exponential behavior in the generated code: {{{ $ for n ({20..30}); do time ./Slow $n; done ObsTemp 1 ./Slow $n 0,05s user 0,00s system 85% cpu 0,064 total ObsTemp 1 ./Slow $n 0,08s user 0,00s system 91% cpu 0,092 total ObsTemp 1 ./Slow $n 0,16s user 0,00s system 98% cpu 0,162 total ObsTemp 1 ./Slow $n 0,31s user 0,00s system 99% cpu 0,312 total ObsTemp 1 ./Slow $n 0,62s user 0,00s system 99% cpu 0,622 total ObsTemp 1 ./Slow $n 1,23s user 0,00s system 99% cpu 1,242 total ObsTemp 1 ./Slow $n 2,47s user 0,00s system 99% cpu 2,472 total ObsTemp 1 ./Slow $n 5,11s user 0,00s system 99% cpu 5,112 total ObsTemp 1 ./Slow $n 9,85s user 0,00s system 99% cpu 9,862 total ObsTemp 1 ./Slow $n 19,92s user 0,01s system 100% cpu 19,922 total ^C^C }}} Increasing the iteration count by one causes time it takes to double.5 -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/15143#comment:4 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#15143: Passing an IO value through several functions results in program hanging. -------------------------------------+------------------------------------- Reporter: Burtannia | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.6.1 Component: Compiler | Version: 8.4.2 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Runtime | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by simonpj): Why do you think this is a bug? You are compputing {{{ incTime (incTime ( ... (incTime testObs) ... )) }}} where {{{ incTime :: IO Obs -> IO Obs incTime o = do obs <- o case obs of ObsTime t -> return $ ObsTime (t+1) _ -> o }}} Each call of `incTime` invokes its argument `o` twice. Since `o` is passed in as an argument, GHC ''must'' call it twice in case it has side effects. The alternative code {{{ incTime' o = do obs <- o case obs of ObsTime t -> return $ ObsTime (t+1) _ -> return obs }}} is not semantically equivalent. Imagine called {{{ incTime (do { updRef r (+ 1); return ObsTemp }) }}} then I expect the reference `r` to be incremented twice. But `incTime'` will only increment it once. So each call to `incTime o` calls `o` twice. But in the call `incTime (incTime o)`, we call `incTime o` twice; and each call calls `o` twice. Result: four calls to `o`. If the nest is 3 deep we get eigth calls and so on. In short, this program has exponential runtime ''by design'', and GHC faithfully does what you ask. In short, it looks fine to me. Do you agree? -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/15143#comment:6 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#15143: Passing an IO value through several functions results in program hanging. -------------------------------------+------------------------------------- Reporter: Burtannia | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.6.1 Component: Compiler | Version: 8.4.2 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Runtime | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by Burtannia): Replying to [comment:5 danilo2]: I think you were right that it's to do with the strictness of the value. I don't know a huge amount but here is my interpretation.

{{{ !r <- mr -- | Performance buildLayerFold @t @m @layer layer $! pure r }}}

This performs the monadic action `mr`, binds the result to `r` and forces that value to be fully evaluated. `$! pure r` forces `pure r` to be fully evaluated. Note that `pure r` isn't a value, it's a monadic computation that returns a value. From what I understand, your test:

{{{ !_ <- mr buildLayerFold @t @m @layer layer mr }}}

isn't doing what you think it's doing. `!_ <- mr` says ''perform the monadic action `mr` and strictly evaluate its result''. You then pass the monadic action `mr` as an argument to the function on the next line. Note that the computation `mr` is not strictly evaluated here. Later during the execution, that computation will be performed again but must first be evaluated. I'm presuming this "second evaluation" is why it runs two times slower. Again I'm not 100% sure that I'm correct on this. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/15143#comment:8 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#15143: Passing an IO value through several functions results in program hanging. -------------------------------------+------------------------------------- Reporter: Burtannia | Owner: (none) Type: bug | Status: new Priority: normal | Milestone: 8.6.1 Component: Compiler | Version: 8.4.2 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Runtime | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Rev(s): Wiki Page: | -------------------------------------+------------------------------------- Comment (by simonpj): It is nothing to do with strictness! Consider {{{ foo :: IO Int -> IO Int foo a = do { i1 <- a ; i2 <- a ; return (i1+i2) } }}} This function must perform `a` twice. It is ''not'' ok to "optimise" it to {{{ foo a = do { i1 <- a ; return (i1+i1) } }}} Reason: `a` might have side effects (which must be performed twice) and it might return different values on its successive calls. In the example of this ticket, in `incTime` the action `o` must be called twice. And in the particular example, the action is another call to `incTime` which calls its `o` twice; and so on. Result: 2^n calls of the final action, hence exponential behaviour. Strictness and bangs have no effect on this story -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/15143#comment:10 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler