
Hi. I'm using the hslogger library for logging pure code, using the following function: uLog :: Priority -> String -> a -> a uLog pri str x = unsafePerformIO $ logM rootLoggerName pri str >> return x Everything was working fine, till I used uLog on a very accessed function. Then the program started to fail with: thread blocked indefinitely in an MVar operation I've changed uLog to: uLog :: Priority -> String -> a -> a uLog pri str x = unsafePerformIO $ hPutStrLn stderr (show str) >> return x And I noticed on the log that two messages were sent "at the same time" on the point where the version with hslogger fails: "canonicate 4 "canonicate 1 \r\n\t\t\t\t\t\t\t\tRio Branco = rio branco" "canonicate 2 AC\r\n\t\t\t\t\t\t\t\t = ac" ac = ac" They were sent as (in any order): "canonicate 4 ac = ac" "canonicate 1 \r\n\t\t\t\t\t\t\t\tRio Branco = rio branco" "canonicate 2 AC\r\n\t\t\t\t\t\t\t\t = ac" I tried changing hslogger to avoid calling modifyMVar when getting logger for rootLoggerName, and using withMVar instead, but the problem persisted. I tried to create a simple test case to reproduce the problem, but I couldn't, all test cases I created worked as expected. As I was with no other ideas, I tried some things that make little sense. This happens with optimization or without it. Following http://hackage.haskell.org/trac/ghc/ticket/5859 I tried using -fno-state-hack, but the problem persisted. I tried adding NOINLINE to uLog, without success. I also tried changing unsafePerformIO to unsafeDupablePerformIO. I thought that the only thing I needed to take care while using unsafePerformIO was knowing that the time of execution is undetermined and that it could even run more than once. This is not a problem for my logging. Is there something else I should be aware while using unsafePerformIO? Greetings. -- marcot http://marcot.eti.br/

On Fri, Jul 27, 2012 at 9:52 AM, Marco Túlio Gontijo e Silva
I thought that the only thing I needed to take care while using unsafePerformIO was knowing that the time of execution is undetermined and that it could even run more than once. This is not a problem for my logging. Is there something else I should be aware while using unsafePerformIO?
Another thing to be aware of is that unsafePerformIO and STM don't interact well. In particular, STM will abort doomed transactions. If the transaction is IO that has exception handlers set up, those handlers won't be run. This is the case for unsafeIOToSTM, but I'm not sure if it's the case for unsafePerformIO as well. Are you using STM in your program? Also, what version of GHC are you using? -Joey

Hi Joey.
Thanks for your answer.
On Sun, Jul 29, 2012 at 3:16 PM, Joey Adams
On Fri, Jul 27, 2012 at 9:52 AM, Marco Túlio Gontijo e Silva
wrote: I thought that the only thing I needed to take care while using unsafePerformIO was knowing that the time of execution is undetermined and that it could even run more than once. This is not a problem for my logging. Is there something else I should be aware while using unsafePerformIO?
Another thing to be aware of is that unsafePerformIO and STM don't interact well. In particular, STM will abort doomed transactions. If the transaction is IO that has exception handlers set up, those handlers won't be run. This is the case for unsafeIOToSTM, but I'm not sure if it's the case for unsafePerformIO as well.
Are you using STM in your program? Also, what version of GHC are you using?
No, not in my program. Maybe a library that I use uses it, but not that I'm aware of. I'm using GHC version 7.4.1, I'll try it with 7.4.2 later. Greetings! (...) -- marcot http://marcot.eti.br/

On 27 July 2012 14:52, Marco Túlio Gontijo e Silva
thread blocked indefinitely in an MVar operation
IIRC, that means that a thread is blocked on an MVar and the MVar is only reachable by that thread. You said you tried adding NOINLINE, which is usually required for unsafePerformIO. Did you make sure to recompile everything from scratch after doing so? Other than that, you may ask on the glasgow-haskell-users mailing list as this is read more frequently by the GHC team. / Thomas -- Push the envelope. Watch it bend.

On Mon, Jul 30, 2012 at 1:54 AM, Thomas Schilling
On 27 July 2012 14:52, Marco Túlio Gontijo e Silva
wrote: thread blocked indefinitely in an MVar operation
IIRC, that means that a thread is blocked on an MVar and the MVar is only reachable by that thread.
This sounds right. STM has noticed that there's a thread waiting for something that will never be available. It seems it have found a deadlock. I once tried mixing IO and STM actions (IO inside STM) and ended up rewriting the code to seperate the two. Before the rewrite, I got some of the strangest and most unpredictable errors I've ever seen in a Haskell program. I reckon this could be related. Here's the thread from back then: http://www.haskell.org/pipermail/haskell-cafe/2012-January/098453.html -- Johan Brinch
participants (4)
-
Joey Adams
-
Johan Brinch
-
Marco Túlio Gontijo e Silva
-
Thomas Schilling