# Web server subprocess logging to stdout sometimes not available until after subprocess terminates **URL:** \ **Category:** Questions & Answers\ **Tags:** web-server, logging\ **Created:** [January 28, 2023, 7:11pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673 "2023-01-28T19:11:18Z")\ **Posts on this page:** 13\ **Page:** 1
**Author:** ![joeld](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/joeld/32/38_2.png) [@joeld](https://racket.discourse.group/u/joeld)\ **Post date:** [January 28, 2023, 7:11pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/1 "2023-01-28T19:11:18Z")
I’m running `raco static-web` from inside another Racket program using `subprocess`\[1\], and, inside a thread, monitoring the subprocess’s stdout with `sync/enable-break`. The weird thing is that with `raco static-web` in particular, the output sent by that command to stdout is not picked up by my program until the `raco` process is killed in some way. [Example Gist](https://gist.github.com/otherjoel/4e84726ba97ec5884cdeee82b188f0d9). See the screenshot at the bottom also. (I’m working on this for a GUI app, but I created this not-exactly-MVE to remove GUI stuff from the equation.) This is running on macOS. Twist: with _any other_ long-running program I run this way (`make`, `raco pollen start`, etc.), stuff appears on the port as it is generated by the subprocess, as expected. So it must be something to do with [the way raco static-web does logging](https://github.com/samdphillips/raco-static-web/blob/main/main.rkt#L41-L45), or more specifically with the dispatcher created by [`make` in `web-server/dispatchers/dispatch-logresp`](https://docs.racket-lang.org/web-server-internal/dispatch-logresp.html#%28def._%28%28lib._web-server%2Fdispatchers%2Fdispatch-logresp..rkt%29._make%29%29). * * * 1. I know that it would probably be better for me just to run the web server directly inside my own program, and that’s probably the direction I’ll go eventually. But I am very curious to understand what causes this behavior anyway. ---
**Author:** ![sorawee](https://avatars.discourse-cdn.com/v4/letter/s/ea5d25/32.png) [@sorawee](https://racket.discourse.group/u/sorawee)\ **Post date:** [January 28, 2023, 7:52pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/2 "2023-01-28T19:52:10Z")
Can you install `raco static-web` from source, and revert back to df097e1475f1f6cb648f2d457e94a3dd2659542e, which is the commit right before I changed `raco static-web` to use `dispatch-logresp`? Do you get the same behavior? ---
**Author:** ![joeld](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/joeld/32/38_2.png) [@joeld](https://racket.discourse.group/u/joeld)\ **Post date:** [January 28, 2023, 9:00pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/3 "2023-01-28T21:00:42Z")
In fact I have that package installed via `--link` from a local git clone. And yes, I do get the same behavior after checking out `df097e14`, deleting the `compiled` folder, doing `raco pkg setup raco-static-web` and restarting DrRacket. ---
**Author:** ![sorawee](https://avatars.discourse-cdn.com/v4/letter/s/ea5d25/32.png) [@sorawee](https://racket.discourse.group/u/sorawee)\ **Post date:** [January 28, 2023, 9:41pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/4 "2023-01-28T21:41:04Z")
So I think the difference is that Pollen uses [stderr](https://github.com/mbutterick/pollen/blob/99c43e6ad360f7735ebc9c6e70a08dec5829d64a/pollen/private/command.rkt#L48) for those messages, and stderr is not buffered. On the other hand, `raco static-web` uses stdout, which got buffered. I don’t know how to fix that though. ---
**Author:** ![joeld](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/joeld/32/38_2.png) [@joeld](https://racket.discourse.group/u/joeld)\ **Post date:** [January 29, 2023, 4:10pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/5 "2023-01-29T16:10:40Z")
Ok, that rings some bells. The stdout port returned by `subprocess` is initially set to a buffer mode of `'block`, and I can set it to `'none`… ```scheme (displayln (list (file-stream-buffer-mode out) (file-stream-buffer-mode out 'none) (file-stream-buffer-mode out))) ;; → '(block # none) ``` …but this doesn’t keep it from behaving like a block-buffered port. I guess maybe that part is up to the OS. Maybe the logger could be modified to `flush-output` more frequently? But now that the mystery is cleared up somewhat, I can move on to moving the web server inside my code rather than doing a subprocess. ---
**Author:** ![samth](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/samth/32/3_2.png) [@samth](https://racket.discourse.group/u/samth)\ **Post date:** [January 30, 2023, 3:40pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/6 "2023-01-30T15:40:58Z")
Really the fix here seems like it would be to use Racket's logging infrastructure, rather than printing directly to stdout. ---
**Author:** ![joeld](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/joeld/32/38_2.png) [@joeld](https://racket.discourse.group/u/joeld)\ **Post date:** [January 30, 2023, 5:55pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/7 "2023-01-30T17:55:36Z")
> [@samth](#): > > Really the fix here seems like it would be to use Racket's logging infrastructure Yes, this is what I had in mind as part of inlining the web server code. (I assume it’s not possible to listen to a logger from another program running under a whole other instance of `racket` in a subprocess…right?) ---
**Author:** ![samth](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/samth/32/3_2.png) [@samth](https://racket.discourse.group/u/samth)\ **Post date:** [January 30, 2023, 6:23pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/8 "2023-01-30T18:23:27Z")
You would need some kind of inter-process communication, and there isn't any infrastructure that I know of for doing that automatically yet. Logging can automatically go to syslog, and you could read from that, or you could build your own IPC. ---
**Author:** ![sorawee](https://avatars.discourse-cdn.com/v4/letter/s/ea5d25/32.png) [@sorawee](https://racket.discourse.group/u/sorawee)\ **Post date:** [January 30, 2023, 6:23pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/9 "2023-01-30T18:23:47Z")
Sorry, I'm a bit lost on why you want to run another Racket program via subprocess. Couldn't you do something like this instead: ```scheme #lang racket (require raco/all-tools) (define static-web (hash-ref (all-tools) "static-web")) (dynamic-require (second static-web) #f) ``` Here, you have full control of the application: you can `parameterize` `current-output-port`, `current-command-line-arguments`, and whatnot. And you can run it in a separate thread. ---
**Author:** ![joeld](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/joeld/32/38_2.png) [@joeld](https://racket.discourse.group/u/joeld)\ **Post date:** [January 30, 2023, 6:48pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/10 "2023-01-30T18:48:28Z")
> [@sorawee](#): > > Sorry, I'm a bit lost on why you want to run another Racket program via subprocess. I’ve been trying to make a GUI app that would run arbitrary command-line programs (or scripts) and display the output in an editor canvas in real time, just as if you were running it in the console. So it’s not that I specifically wanted to run _a Racket program_ via a subprocess, I just wanted to be able to run _anything_ and see the output in real time. My approach works great with all the commands/scripts I tested except for `raco static-web`. And I was too curious about why that would possibly be to drop the issue. Assuming the problem is caused by block-buffering stdout outside of Racket’s control, there are probably many other programs/scripts that would exhibit the same problem when run from my app. And maybe there isn’t a reliable way to make this app without delving into pseudo-tty stuff, which, “that way lies madness”, likely. ---
**Author:** ![soegaard](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/soegaard/32/19_2.png) [@soegaard](https://racket.discourse.group/u/soegaard)\ **Post date:** [January 30, 2023, 7:12pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/11 "2023-01-30T19:12:26Z")
If you run static-web in the terminal, do you see the output sent to stdout right away? ---
**Author:** ![benknoble](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/benknoble/32/16_2.png) [@benknoble](https://racket.discourse.group/u/benknoble)\ **Post date:** [January 30, 2023, 7:37pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/12 "2023-01-30T19:37:53Z")
I do, for example, typically see it immediately. But I have seen issues where in Github Actions the output is incorrectly buffered. I can't remember if that was using logging infrastructure or print/displayln. ---
**Author:** ![joeld](https://yyz2.discourse-cdn.com/free1/user_avatar/racket.discourse.group/joeld/32/38_2.png) [@joeld](https://racket.discourse.group/u/joeld)\ **Post date:** [January 30, 2023, 7:41pm UTC](https://racket.discourse.group/t/web-server-subprocess-logging-to-stdout-sometimes-not-available-until-after-subprocess-terminates/1673/13 "2023-01-30T19:41:35Z")
> [@soegaard](#): > > If you run static-web in the terminal, do you see the output sent to stdout right away? Yep! Though, in that case, `raco` is being run from inside an interactive shell with a [TTY device](http://www.linusakesson.net/programming/tty/), which IIUC is not the case when running it via [`subprocess`](https://docs.racket-lang.org/reference/subprocess.html#%28def._%28%28quote._~23~25kernel%29._subprocess%29%29).