Log GHC configure output on `stack -v setup` #3740

krisis · 2018-01-03T05:33:23Z

If -v global flag is passed to stack-setup subcommand we log the GHC
configure output.
Ref: #3716

Any changes that could be relevant to users have been recorded in the ChangeLog.md
The documentation has been updated, if necessary.

This PR was (manually) tested by running stack --verbose setup --reinstall on a new project directory created by stack new testConfigure new-template.

Excerpt of relevant logs from above test.

2018-01-03 10:49:29.280452: [debug] Process finished in 1550ms: /home/kp/.stack/programs/x86_64-linux/ghc-7.10.3.temp/ghc-7.10.3/configure --prefix=/home/kp/.stack/programs/x86_64-linux/ghc-7.10.3/
@(subs/rio/src/RIO/Process.hs:191:3)
2018-01-03 10:49:29.280793: [debug] Run process within /home/kp/.stack/programs/x86_64-linux/ghc-7.10.3.temp/ghc-7.10.3/: /usr/bin/make install
@(subs/rio/src/RIO/Process.hs:191:3)
2018-01-03 10:49:29.304283: [info] /usr/bin/make -r --no-print-directory -f ghc.mk install BINDIST=YES NO_INCLUDE_DEPS=YES
@(Stack/Setup.hs:1096:54)
2018-01-03 10:49:29.737966: [info] "rm" -f utils/ghc-pkg/dist-install/build/Version.hs  
@(Stack/Setup.hs:1096:54)
2018-01-03 10:49:29.739872: [info] echo "module Version where"                    >> utils/ghc-pkg/dist-install/build/Version.hs
@(Stack/Setup.hs:1096:54)
2018-01-03 10:49:29.741026: [info] echo "version, targetOS, targetARCH :: String" >> utils/ghc-pkg/dist-install/build/Version.hs
@(Stack/Setup.hs:1096:54)
2018-01-03 10:49:29.742170: [info] echo "version    = \"7.10.3\""      >> utils/ghc-pkg/dist-install/build/Version.hs

krisis · 2018-01-03T05:45:42Z

src/Stack/Setup.hs

+            result <- case logLevel of
+              LevelDebug -> do
+                let logLines = CB.lines .| CL.mapM_ (logInfo . T.decodeUtf8With T.lenientDecode)
+                withWorkingDir wd


I didn't notice earlier that the indentation is off. I shall correct this in subsequent submissions along with other review comments.

mgsloan · 2018-01-03T07:09:35Z

src/Stack/Setup.hs

-                    -- Calling the ./configure script requires that stdin is
-                    -- open
-                    . setStdin (useHandleOpen stdin)
+            result <- case logLevel of


Can avoid the manual plumbing of logLevel by doing something like logLevel <- logMinLevel <$> view logOptionsL

mgsloan · 2018-01-03T07:26:17Z

src/Stack/Setup.hs

+            result <- case logLevel of
+              LevelDebug -> do
+                let logLines = CB.lines .| CL.mapM_ (logInfo . T.decodeUtf8With T.lenientDecode)
+                withWorkingDir wd


This is good code! There are some existing utility functions for this, though - Stack.Prelude.logProcessStderrStdout. This stuff got moved around recently in #3730

It appears that this is the only place in the codebase that uses logProcessStderrStdout. I'd recommend just removing the function entirely from Stack.Prelude and keeping the functionality here. No need to provide general utility functions if they're not of general utility :)

FWIW, this is something I would have done myself in #3730 had I noticed, so good catch to you both.

Though, to me this sort of thing seems like a useful thing for a future rio - process. It is not uncommon to want to involve process output in your log while still keeping your log format.

I am leaving logProcessStderrStdout as it is being used here.

snoyberg · 2018-01-03T10:08:25Z

src/Stack/Setup.hs

-                    . setStdin (useHandleOpen stdin)
+            result <- case logLevel of
+              LevelDebug -> do
+                let logLines = CB.lines .| CL.mapM_ (logInfo . T.decodeUtf8With T.lenientDecode)


It's slightly less efficient, but assuming it gives the output you're looking for, you could use logDebug here instead, and then unconditionally use this implementation, and totally bypass analyzing the logLevel. I'm not too concerned about the performance overhead of breaking the output from ./configure into lines and then potentially ignoring them, so I'd lean in that direction for the code simplification it would yield.

I am not sure I follow how we can avoid analyzing loglevel. If logLevel is LogDebug (i.e, stack-setup was invoked with -v) we need to read stdout of configure script and print it in stack command's stdout. Otherwise, we should not print anything. If we used logDebug in both the cases, wouldn't users who ran stack-setup without -v complain about the verbosity?

logDebug will only produce output if Stack is run with -v.

snoyberg · 2018-01-04T03:05:09Z

src/Stack/Setup.hs

+                  $ withEnvOverride menv'
+                  $ withProc cmd args
+                  $ try
+                  . (flip withLoggedProcess_ $ \p ->


What's the reason for the switch to withLoggedProcess_ here, instead of say withProcess_? Quoting from the docs:

This will store all output from stdout and stderr in memory for better error messages.

It seems like that's redundant with turning on the verbose debugging here.

I shall update the PR using withProcess_.

snoyberg · 2018-01-04T12:37:11Z

src/Stack/Setup.hs

-                    -- open
-                    . setStdin (useHandleOpen stdin)
+            result <- do
+                let logLines = CL.mapM_ (logDebug . T.decodeUtf8With T.lenientDecode)


This implementation is different from the one in logProcessStderrStdout, which includes a call to CB.lines:

let logLines = CB.lines .| CL.mapM_ (logInfo . decodeUtf8With lenientDecode)

As implemented here, it will not break the output up into individual lines.

Another difference is that I have used concurrently_ since we are ignoring the return values subsequently.

krisis · 2018-01-04T12:43:25Z

Yes. I misunderstood your previous comment on code simplification and thought you were suggesting removal of CB.lines. I shall add it back.

If -v global flag is passed to stack-setup subcommand we log the GHC configure output. Ref: commercialhaskell#3716

Also fix function name (typo) referred in comments.

This allows us to reuse sinkProcessStderrStdout to print verbose output while configuring GHC.

snoyberg · 2018-01-07T07:55:29Z

src/Stack/Prelude.hs

@@ -76,8 +76,7 @@ sinkProcessStderrStdout
  -> RIO env (e,o)
 sinkProcessStderrStdout name args sinkStderr sinkStdout =
  withProc name args $ \pc0 -> do
-    let pc = setStdin closed


I'm not in favor of changing this default—which IMO is the right default—for this one case, which should be considered an exception. I preferred the previous approach. If the goal is to reduce code duplication, I would recommend changing the function to take a ProcessConfig instead, or something along those lines.

Orthogonal to this PR... I think we do have to change this default. I found another part of the code base which is expecting a working stdin in a subprocess: configuring a package with build-type: Configure. So let's move ahead with this as is.

krisis commented Jan 3, 2018

View reviewed changes

mgsloan reviewed Jan 3, 2018

View reviewed changes

snoyberg reviewed Jan 3, 2018

View reviewed changes

krisis force-pushed the issue/3716 branch from 048f8e0 to b0d5361 Compare January 3, 2018 19:04

snoyberg reviewed Jan 4, 2018

View reviewed changes

krisis force-pushed the issue/3716 branch from b0d5361 to dc081c6 Compare January 4, 2018 04:02

snoyberg reviewed Jan 4, 2018

View reviewed changes

snoyberg approved these changes Jan 4, 2018

View reviewed changes

Krishnan Parthasarathi added 7 commits January 5, 2018 13:47

Log GHC configure output on stack -v setup

fcf1435

If -v global flag is passed to stack-setup subcommand we log the GHC configure output. Ref: commercialhaskell#3716

Fix shadowing warning and indentation

3b7f5dd

Extract logLevel from env

d91b1a0

Avoid explicit case analysis of logLevel

8421402

Use withProcess_ since process output is logged anyway

724c444

Also fix function name (typo) referred in comments.

Add back splitting stdout into lines

fba0b2c

Leave stdin open in withProc, sinkProcessStderrStdout

bf84086

This allows us to reuse sinkProcessStderrStdout to print verbose output while configuring GHC.

krisis force-pushed the issue/3716 branch from 1df52f7 to bf84086 Compare January 5, 2018 09:35

snoyberg requested changes Jan 7, 2018

View reviewed changes

snoyberg merged commit bf84086 into commercialhaskell:master Jan 7, 2018

snoyberg mentioned this pull request Jan 7, 2018

"stack setup --verbose" should also cause verbose output of GHC configure process if possible #3716

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Log GHC configure output on `stack -v setup` #3740

Log GHC configure output on `stack -v setup` #3740

krisis commented Jan 3, 2018

krisis Jan 3, 2018

mgsloan Jan 3, 2018

mgsloan Jan 3, 2018

snoyberg Jan 3, 2018

mgsloan Jan 4, 2018

krisis Jan 4, 2018

snoyberg Jan 3, 2018

krisis Jan 3, 2018

snoyberg Jan 3, 2018

snoyberg Jan 4, 2018

krisis Jan 4, 2018

snoyberg Jan 4, 2018

krisis Jan 4, 2018

krisis commented Jan 4, 2018

snoyberg Jan 7, 2018

snoyberg Jan 7, 2018

Log GHC configure output on stack -v setup #3740

Log GHC configure output on stack -v setup #3740

Conversation

krisis commented Jan 3, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

krisis commented Jan 4, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Log GHC configure output on `stack -v setup` #3740

Log GHC configure output on `stack -v setup` #3740