From 85b534833fb28c64b2d9c884bc05f2b03b6e3862 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?J=C3=B6rn=20Friedrich=20Dreyer?= Date: Fri, 20 Mar 2020 16:58:48 +0100 Subject: [PATCH] Add debugging docs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Jörn Friedrich Dreyer --- docs/debugging.md | 217 ++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 217 insertions(+) create mode 100644 docs/debugging.md diff --git a/docs/debugging.md b/docs/debugging.md new file mode 100644 index 0000000000..4aa2299e85 --- /dev/null +++ b/docs/debugging.md @@ -0,0 +1,217 @@ +--- +title: "Debugging" +date: 2020-03-19T08:21:00+01:00 +weight: 50 +geekdocRepo: https://github.com/owncloud/ocis +geekdocEditPath: edit/master/docs +geekdocFilePath: debugging.md +--- + +## Debugging + +As a single binary for easy deployment running `ocis server` just forks itself to start all the services, which makes debugging those processes a little harder. + +Ultimately, we want to be able to stop a single service using eg. `ocis kill phoenix` so that you can start the service you want to debug in debug mode. We need to [change the way we fork processes](https://github.com/owncloud/ocis/issues/77) though, otherwise the runtime will automatically restart a service if killed. + +### Start ocis + +For debugging there are two workflows that work well, depending on your preferences. + +#### Use the debug binary and attach to the process as needed + +Run the debug binary with `OCIS_LOG_LEVEL=debug bin/ocis-debug server` and then find the service you want to debug using: + +```console +# ps ax | grep ocis +12837 pts/1 Sl+ 0:00 bin/ocis-debug server +12845 pts/1 Sl 0:00 bin/ocis-debug graph +12847 pts/1 Sl 0:00 bin/ocis-debug reva-auth-bearer +12848 pts/1 Sl 0:00 bin/ocis-debug graph-explorer +12849 pts/1 Sl 0:00 bin/ocis-debug ocs +12850 pts/1 Sl 0:00 bin/ocis-debug reva-storage-oc-data +12863 pts/1 Sl 0:00 bin/ocis-debug webdav +12874 pts/1 Sl 0:00 bin/ocis-debug reva-frontend +12897 pts/1 Sl 0:00 bin/ocis-debug reva-sharing +12905 pts/1 Sl 0:00 bin/ocis-debug reva-gateway +12912 pts/1 Sl 0:00 bin/ocis-debug reva-storage-home +12920 pts/1 Sl 0:00 bin/ocis-debug reva-users +12929 pts/1 Sl 0:00 bin/ocis-debug glauth +12940 pts/1 Sl 0:00 bin/ocis-debug reva-storage-home-data +12948 pts/1 Sl 0:00 bin/ocis-debug konnectd +12952 pts/1 Sl 0:00 bin/ocis-debug proxy +12961 pts/1 Sl 0:00 bin/ocis-debug thumbnails +12971 pts/1 Sl 0:00 bin/ocis-debug reva-storage-oc +12981 pts/1 Sl 0:00 bin/ocis-debug web +12993 pts/1 Sl 0:00 bin/ocis-debug api +12998 pts/1 Sl 0:00 bin/ocis-debug registry +13004 pts/1 Sl 0:00 bin/ocis-debug phoenix +13015 pts/1 Sl 0:00 bin/ocis-debug reva-auth-basic +``` + +Then you can set a breakpoint in the service you need and attach to the process via processid. To debug the `reva-sharing` service the VS Code `launch.json` would look like this: + +```json +{ + "version": "0.2.0", + "configurations": [ + { + "name": "ocis attach", + "type": "go", + "request": "attach", + "mode": "local", + "processId": 12897, + } + ] +} +``` + +#### Start all services independently to replace one of them with a debug process + +1. You can use this `./ocis.sh` script to start all services independently, so they don't get restrarted by the runtime when you kill them: +```bash +#/bin/sh +LOG_LEVEL="debug" + +bin/ocis --log-level=$LOG_LEVEL micro & + +bin/ocis --log-level=$LOG_LEVEL glauth & +bin/ocis --log-level=$LOG_LEVEL graph-explorer & +bin/ocis --log-level=$LOG_LEVEL graph & +#bin/ocis --log-level=$LOG_LEVEL hello & +bin/ocis --log-level=$LOG_LEVEL konnectd & +#bin/ocis --log-level=$LOG_LEVEL ocs & +bin/ocis --log-level=$LOG_LEVEL phoenix & +bin/ocis --log-level=$LOG_LEVEL reva-auth-basic & +bin/ocis --log-level=$LOG_LEVEL reva-auth-bearer & +bin/ocis --log-level=$LOG_LEVEL reva-frontend & +bin/ocis --log-level=$LOG_LEVEL reva-gateway & +bin/ocis --log-level=$LOG_LEVEL reva-sharing & +bin/ocis --log-level=$LOG_LEVEL reva-storage-home & +bin/ocis --log-level=$LOG_LEVEL reva-storage-home-data & +bin/ocis --log-level=$LOG_LEVEL reva-storage-oc & +bin/ocis --log-level=$LOG_LEVEL reva-storage-oc-data & +bin/ocis --log-level=$LOG_LEVEL reva-storage-root & +bin/ocis --log-level=$LOG_LEVEL reva-users & +#bin/ocis --log-level=$LOG_LEVEL webdav + +bin/ocis --log-level=$LOG_LEVEL proxy & +``` + +2. Get the list of running processes: + +```console +# ps ax | grep ocis +12837 pts/1 Sl+ 0:00 bin/ocis-debug server +12845 pts/1 Sl 0:00 bin/ocis-debug graph +12847 pts/1 Sl 0:00 bin/ocis-debug reva-auth-bearer +12848 pts/1 Sl 0:00 bin/ocis-debug graph-explorer +12849 pts/1 Sl 0:00 bin/ocis-debug ocs +12850 pts/1 Sl 0:00 bin/ocis-debug reva-storage-oc-data +12863 pts/1 Sl 0:00 bin/ocis-debug webdav +12874 pts/1 Sl 0:00 bin/ocis-debug reva-frontend +12897 pts/1 Sl 0:00 bin/ocis-debug reva-sharing +12905 pts/1 Sl 0:00 bin/ocis-debug reva-gateway +12912 pts/1 Sl 0:00 bin/ocis-debug reva-storage-home +12920 pts/1 Sl 0:00 bin/ocis-debug reva-users +12929 pts/1 Sl 0:00 bin/ocis-debug glauth +12940 pts/1 Sl 0:00 bin/ocis-debug reva-storage-home-data +12948 pts/1 Sl 0:00 bin/ocis-debug konnectd +12952 pts/1 Sl 0:00 bin/ocis-debug proxy +12961 pts/1 Sl 0:00 bin/ocis-debug thumbnails +12971 pts/1 Sl 0:00 bin/ocis-debug reva-storage-oc +12981 pts/1 Sl 0:00 bin/ocis-debug web +12993 pts/1 Sl 0:00 bin/ocis-debug api +12998 pts/1 Sl 0:00 bin/ocis-debug registry +13004 pts/1 Sl 0:00 bin/ocis-debug phoenix +13015 pts/1 Sl 0:00 bin/ocis-debug reva-auth-basic +``` + +3. Kill the service you want to start in debug mode: + + +```console +# kill 17628 +``` + +4. Start the service you are interested in in debug mode. When using make to build the binary there is already a `bin/ocis-debug` binary for you. When running an IDE tell it which service to start by providing the corresponding sub command, eg. `bin\ocis-debug reva-frontend`. + +### Gather error messages + +We recommend you collect all related information in a single file or in a github issue. Let us start with an error that pops up in the Web UI: + +> Error while sharing. +> error sending a grpc stat request + +This popped up when I tried to add `marie` as a collaborator in phoenix. That triggers a request to the server which I copied as curl. We can strip a lot of headers and the gist of it is: + +```console +# curl 'https://localhost:9200/ocs/v1.php/apps/files_sharing/api/v1/shares' -d 'shareType=0&shareWith=marie&path=%2FNeuer+Ordner&permissions=1' -u einstein:relativity -k -v | xmllint -format - +[... headers ...] + + + + error + 998 + error sending a grpc stat request + + +``` + +{{< hint [info] >}} +The username and password only work when basic auth is available. Otherwise you have to obtain a bearer token, eg. by grabbing it from the browser. +{{< /hint >}} +{{< hint [danger] >}} +TODO add ocis cli tool to obtain a bearer token. +{{< /hint >}} + +We also have a few interesting log entries: + +``` +0:43PM INF home/jfd/go/pkg/mod/github.com/cs3org/reva@v0.0.2-0.20200318111623-a2f97d4aa741/internal/grpc/interceptors/log/log.go:69 > unary code=OK end="18/Mar/2020:22:43:40 +0100" from=tcp://[::1]:44078 pid=17836 pkg=rgrpc start="18/Mar/2020:22:43:40 +0100" time_ns=95841 traceid=b4eb9a9f45921f7d3632523ca32a42b0 uri=/cs3.storage.registry.v1beta1.RegistryAPI/GetStorageProvider user-agent=grpc-go/1.26.0 +10:43PM ERR home/jfd/go/pkg/mod/github.com/cs3org/reva@v0.0.2-0.20200318111623-a2f97d4aa741/internal/grpc/interceptors/log/log.go:69 > unary code=Unknown end="18/Mar/2020:22:43:40 +0100" from=tcp://[::1]:43910 pid=17836 pkg=rgrpc start="18/Mar/2020:22:43:40 +0100" time_ns=586115 traceid=b4eb9a9f45921f7d3632523ca32a42b0 uri=/cs3.gateway.v1beta1.GatewayAPI/Stat user-agent=grpc-go/1.26.0 +10:43PM ERR home/jfd/go/pkg/mod/github.com/cs3org/reva@v0.0.2-0.20200318111623-a2f97d4aa741/internal/http/services/owncloud/ocs/reqres.go:94 > error sending a grpc stat request error="rpc error: code = Unknown desc = gateway: error calling Stat: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp [::1]:9152: connect: connection refused\"" pid=17832 pkg=rhttp traceid=b4eb9a9f45921f7d3632523ca32a42b0 +``` + +{{< hint [danger] >}} +TODO return the trace id in the response so we can correlate easier. For reva tracked in https://github.com/cs3org/reva/issues/587 +{{< /hint >}} + +The last line gives us a hint where the log message originated: `.../github.com/cs3org/reva@v0.0.2-0.20200318111623-a2f97d4aa741/internal/http/services/owncloud/ocs/reqres.go:94`. Which looks like this: + +```go +89: // WriteOCSResponse handles writing ocs responses in json and xml +90: func WriteOCSResponse(w http.ResponseWriter, r *http.Request, res *Response, err error) { +91: var encoded []byte +92: +93: if err != nil { +94: appctx.GetLogger(r.Context()).Error().Err(err).Msg(res.OCS.Meta.Message) +95: } +``` + +Ok, so this seems to be a convenience method that is called from multiple places an also handles errors. Unfortunately, this hides the actual source of the error. We could set a breakpoint in line 94 and reproduce the problem, which can be a lot harder than just clicking the share button or sending a curl request again. So let us see what else the log tells us. + +The previous line tells us that a Stat request failed: `uri=/cs3.gateway.v1beta1.GatewayAPI/Stat`. This time the line is written by the grpc log interceptor. What else is there? + +The first line tells us that looking up the responsible storage provider seems to have succeeded: `uri=/cs3.storage.registry.v1beta1.RegistryAPI/GetStorageProvider`. + +At this point it your familiarity with the codebase starts to become a factor. If you are new you should probably go back to setting a break point on the log line and check the stack trace. + +Debug wherever the call trace leads you to ... good luck! + +### Managing dependencies and testing changes + +You can either run and manage the services independently, or you can update the `go.mod` file and replace dependencies with your local version. + +To debug the reva frontend we need to add two replacements: +``` +// use the local ocis-reva repo +replace github.com/owncloud/ocis-reva => ../ocis-reva +// also use the local reva repo +replace github.com/cs3org/reva => ../reva +``` +{{< hint [info] >}} +The username and password only work when basic auth is available. Otherwise you have to obtain a bearer token, eg. by grabbing it from the browser. +{{< /hint >}} + +Rebuild ocis to make sure the dependency is used. It should be sufficient to just restart the service you want to debug. +