Workbench logging improvements about rstudio-docker-products HOT 14 CLOSED

@colearendt Realizing that #2 could use some more info for @nahara7. To build this locally for her to see, it appears you would run the following, is that correct? I haven't actually tried the below, just assuming this from reading the Actions build file:

export RSP_VERSION =$(./get-version.py workbench --type=daily)
make server-pro

Yes, I built it using the version returned !

from rstudio-docker-products.

This is work that the IDE team will work on in the future. I'd say that's not likely to happen this year. The Launcher will continue to run as its own standalone process (service) for awhile.

However, the standard logging for both the Launcher and the IDE are in the daily builds. The Launcher will log to its own file under /var/log/rstudio/launcher.

from rstudio-docker-products.

In fact, even when the IDE starts running the Launcher as a subprocess, those logs will still likely not be surfaced through the IDE logs. This is by design and is accepted by the logging standard, because there is so much Launcher logging that it needs to be separate for debugability. The IDE could capture the Launcher logs over stderr and log them within its own logs, but this would be overly cluttered and is not something I recommend.

from rstudio-docker-products.

@colearendt A few questions on this:

1. I'm not sure if the launcher logging changes are in yet, do you know?
2. Is there also a standard way in here to grab the preview builds that we can point Nahara to?
3. This sounds like we would change things to work with the new preview builds- how would we get this to work with the existing builds and new builds? Or would the idea here to be to have a separate startup.sh for the new preview builds?

from rstudio-docker-products.

1 - In discussion with @kevinhankens , we were hopeful that the launcher and RSW logging changes have landed. I'm not sure whether RSW is managing the launcher process or not yet, though
2 - Yes! https://hub.docker.com/r/rstudio/rstudio-workbench-preview or https://github.com/orgs/rstudio/packages/container/package/rstudio-workbench-preview
3 - I haven't thought about this a whole lot. We could pivot startup.sh based on the type of build in the GitHub Actions yaml, or we can get the branch working and then wait for the release of the next version to merge 😄

from rstudio-docker-products.

Awesome, thanks! For 1. It sounds like the launcher logs might be dependent on https://github.com/rstudio/rstudio-pro/pull/2713 but I'm not 100% sure.

from rstudio-docker-products.

Makes sense, thanks @colearendt. I guess I missed that we have builds in Actions for the preview branches. It makes sense to first focus on getting the startup.sh working in a PR for the new preview builds, and that's what I would focus on to start @nahara7 (and please let us know if you need help there). And then we can decide if we change the PR to work currently or wait until the next version is out.

from rstudio-docker-products.

@colearendt Realizing that #2 could use some more info for @nahara7. To build this locally for her to see, it appears you would run the following, is that correct? I haven't actually tried the below, just assuming this from reading the Actions build file:

export RSP_VERSION =$(./get-version.py workbench --type=daily)
make server-pro

from rstudio-docker-products.

Are there any insights on Workbench running launcher as a subprocess in the future ? Possibly a question for @kfeinauer ? I haven't seen this applied in any of the daily builds so far.

from rstudio-docker-products.

@kfeinauer the problem is that in docker containers we have little other option than to put everything on one stream (or separate into two containers). Writing to disk is not possible, so we have to figure out something that does not do that 😞

Have the products (Launcher / Workbench) implemented structured / JSON logging yet? Are there keys that would make clear which logs are which? Logging tools could vastly simplify the filtering after the fact, if so, and we can merge the streams without too much fuss on the container side (trusting that they will be filtered out / separated elsewhere) 😄

from rstudio-docker-products.

Is writing to disk really impossible? You can definitely mount a directory where log files could be written, and mount RSW and Launcher as separate containers (until they are integrated). Would that not be doable?

The products do have JSON logging that identify the product name. Once RSW actually manages the Launcher as a subprocess, it will not be difficult to merge the logging streams together into RSW's logging (stderr) stream.

I know it's not ideal, but we may want to consider running the Launcher in is own container for RSW until this transition work is complete. It's quite a lot of work so it will take some time.

from rstudio-docker-products.

It's not impossible in a technical sense, you definitely can mount a directory for log files, for sure. It is often impossible for customers in the practical sense - this is not how they manage logging (mounting a dedicated log directory that needs to be ReadWriteMany, etc.). Managing ReadWriteMany volumes for our products' data is already a bit of a pain for them, and they have patterns that they already have for managing logs through stdout/stderr. Moreover, from a generic sysadmin point of view, if a container is misbehaving, you immediately check logs with docker logs, kubectl logs, or a UI (Rancher, cloud platforms, etc.). Exec-ing into the container and checking the log directory is just not a pattern that is used in the container world. (And breaking this pattern just makes life harder for sysadmins - debugging issues gets trickier, support takes longer cycles, etc.)

Exciting about the JSON logging though! Although merging the logging streams together will definitely be easier when there is a subprocess, I am hopeful that we can use the pattern we have now to background launcher (or use the pattern here with a supervisor) to keep both things running and the log streams merged.

It is definitely feasible to considering running launcher as its own container. I think I would probably lean towards a supervisor like the link above since (1) we already kinda need that for sssd or similar user provisioning, (2) this is the pattern I implemented for Colorado (separate containers) and it is not straightforward (we do not document which configs are for which service, user provisioning on both is tricky, networking troubles, etc.), (3) most of our docs presume that they are on the same host, (4) it is at odds with our future plans (i.e. we would be planning to revert everything back to one container later).

from rstudio-docker-products.

Thanks for the background information, that's helpful. Good to understand why it's a pain to just log to file.

We can definitely just merge the stderrs together like you mention, with the one caveat being that if both RSW and Launcher log to stderr at the same time you can get intermingling of the log messages (as you noted above). However, this I would imagine would be a very rare occurrence since RSW barely logs anything any way (aside from errors, would should not be frequent in normal operation). Then once RSW starts running Launcher as its own managed subprocess, this issue goes away.

from rstudio-docker-products.

This ticket is done, but there is work to be done later to resolve conflicts and merge once the products are ready for this.

from rstudio-docker-products.