collaboration stacktraces when

[wkloucek]

Describe the bug

The collaboration service has a stacktrace situation when the office /hosting/discovery enpoint can't be reached

Steps to reproduce

This is what I did, but I'm not sure if it reproduces it:

1. Open a document in OnlyOffice
2. restart all pods of Onlyoffice

Expected behavior

No stacktraces

Actual behavior

See stacktraces:

collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office {"level":"error","service":"collaboration","request-id":"c5343830a4bc6a14f4687b1677098465","proto":"HTTP/1.1","method":"GET","path":"/wopi/files/64c16feecca0162b12344f204a5f0003a3265706e0090f9dc431b0812098c5bf/contents","WopiSessionId":"","WopiOverride":"","WopiProof":"xxx","WopiProofOld":"xxx","WopiStamp":"638675124221080000","FileReference":"resource_id:{storage_id:\"08892747-a1d1-42e7-9cd2-1307ce653638\" opaque_id:\"0c910cad-e3d2-4e36-b373-205b9bfa3ddf\" space_id:\"f4a9a983-3f99-45ee-946b-0b5770bfd234\"} path:\".\"","ViewMode":"VIEW_MODE_READ_WRITE","Requester":"idp:\"https://auth.drive.xxx-vp.de/realms/xxx\" opaque_id:\"f4a9a983-3f99-45ee-946b-0b5770bfd234\" type:USER_TYPE_PRIMARY","WopiAppUrl":"https://one.office.xxx-vp.de/hosting/discovery","HttpCode":503,"time":"2024-11-18T07:40:24Z","line":"github.com/owncloud/ocis/v2/services/collaboration/pkg/proofkeys/handler.go:222","message":"WopiDiscovery: wopi app url failed with unexpected code"}
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 2024/11/18 07:40:24 http: panic serving 10.96.3.252:43854: runtime error: invalid memory address or nil pointer dereference
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office goroutine 283803 [running]:
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.(*conn).serve.func1()
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:1903 +0xbe
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office panic({0x55d98f3c1ca0?, 0x55d991673840?})
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	runtime/panic.go:770 +0x132
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/services/collaboration/pkg/proofkeys.(*VerifyHandler).Verify(0xc001e68960, {0xc0011ef067, 0x78f}, {0xc0013ef600, 0x814}, {0xc00201dcc8, 0x12}, {0xc00032f340, 0x158}, {0xc00032f4a0, ...}, ...)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/services/collaboration/pkg/proofkeys/handler.go:114 +0x269
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/services/collaboration/pkg/middleware.ProofKeysMiddleware.func1({0x55d98f9b0a90, 0xc000384fa0}, 0xc001fe0000)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/services/collaboration/pkg/middleware/proofkeys.go:48 +0x31e
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0xc001fe2000?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0xc001da1890?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/services/collaboration/pkg/middleware.CollaborationTracingMiddleware.func1({0x55d98f9b0a90, 0xc000384fa0}, 0xc001fe0000)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/services/collaboration/pkg/middleware/tracing.go:51 +0xeed
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0xc0020299e0?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0x0?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/services/collaboration/pkg/server/http.prepareRoutes.func2.2.1.WopiContextAuthMiddleware.1({0x55d98f9b0a90, 0xc000384fa0}, 0xc0020299e0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/services/collaboration/pkg/middleware/wopicontext.go:163 +0xb96
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0xc0000767c0?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0xc0000767a0?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5.(*Mux).ServeHTTP(0xc001e57200, {0x55d98f9b0a90, 0xc000384fa0}, 0xc0020299e0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/mux.go:73 +0x32f
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5.(*Mux).Mount.func1({0x55d98f9b0a90, 0xc000384fa0}, 0xc0020299e0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/mux.go:327 +0x1bb
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0xc001fca000?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0xc0018d7720?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5.(*Mux).routeHTTP(0xc001e571a0, {0x55d98f9b0a90, 0xc000384fa0}, 0xc0020299e0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/mux.go:459 +0x2e6
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0xc000076990?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0xc000076970?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5.(*Mux).ServeHTTP(0xc001e571a0, {0x55d98f9b0a90, 0xc000384fa0}, 0xc0020299e0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/mux.go:73 +0x32f
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5.(*Mux).Mount.func1({0x55d98f9b0a90, 0xc000384fa0}, 0xc0020299e0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/mux.go:327 +0x1bb
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0xc001fca000?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0xc0011ef004?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5.(*Mux).routeHTTP(0xc001e570e0, {0x55d98f9b0a90, 0xc000384fa0}, 0xc0020299e0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/mux.go:459 +0x2e6
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0x55d98f9a3b50?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0x0?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/services/collaboration/pkg/server/http.prepareRoutes.func1.1({0x55d98f9b0a90, 0xc000384fa0}, 0xc0020298c0)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/services/collaboration/pkg/server/http/server.go:108 +0x51f
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0x7fe813f11e38?, {0x55d98f9b0a90?, 0xc000384fa0?}, 0xc001da1800?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/riandyrn/otelchi.traceware.ServeHTTP({{0xc001e2fb20, 0x19}, {0x55d98f9a5e00, 0xc001e57140}, {0x55d98f9ad690, 0xc001d75e18}, {0x55d98f98f808, 0xc001e5b200}, {0x55d98f9ade10, 0xc001e570e0}, ...}, ...)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/riandyrn/otelchi@v0.10.1/middleware.go:195 +0xd7c
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/ocis-pkg/middleware.ExtractAccountUUID.func1.1({0x7fe813f11e38, 0xc001f86a80}, 0xc002029560)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/ocis-pkg/middleware/account.go:49 +0x4f9
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0x55d99168cb40?, {0x7fe813f11e38?, 0xc001f86a80?}, 0xc002326dc0?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/services/collaboration/pkg/server/http.Server.AccessLog.func11.1({0x55d98f9acc20, 0xc001f80700}, 0xc002029560)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/services/collaboration/pkg/middleware/accesslog.go:21 +0x130
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0xc0000358f0?, {0x55d98f9acc20?, 0xc001f80700?}, 0xc001d65962?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/owncloud/ocis/v2/services/collaboration/pkg/server/http.Server.Version.func10.1({0x55d98f9acc20, 0xc001f80700}, 0xc002029560)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/owncloud/ocis/v2/ocis-pkg/middleware/version.go:18 +0xfd
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0x55d98f9b6750?, {0x55d98f9acc20?, 0xc001f80700?}, 0x55d98efaeb90?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5/middleware.RequestID.func1({0x55d98f9acc20, 0xc001f80700}, 0xc002029440)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/middleware/request_id.go:76 +0x20e
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.HandlerFunc.ServeHTTP(0x55d98f9b6788?, {0x55d98f9acc20?, 0xc001f80700?}, 0x55d991678050?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2171 +0x29
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office github.com/go-chi/chi/v5.(*Mux).ServeHTTP(0xc001e570e0, {0x55d98f9acc20, 0xc001f80700}, 0xc002029320)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	github.com/go-chi/chi/v5@v5.1.0/mux.go:90 +0x2ee
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.serverHandler.ServeHTTP({0xc0000357d0?}, {0x55d98f9acc20?, 0xc001f80700?}, 0x6?)
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:3142 +0x8e
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office net/http.(*conn).serve(0xc0011e6b40, {0x55d98f9b6750, 0xc001e69a10})
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:2044 +0x5e8
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office created by net/http.(*Server).Serve in goroutine 107
collaboration-xxx-office-dd7655c47-chbxh collaboration-xxx-office 	net/http/server.go:3290 +0x4b4

Setup

oCIS 7.0.0-rc.2 in Kubernetes via the oCIS Helm Chart

[micbar]

@jvillafanez Please take a look.

[jvillafanez]

Couple of things:

• The cause seems to be a variable shadowing in https://github.com/owncloud/ocis/blob/master/services/collaboration/pkg/proofkeys/handler.go#L223 . Basically, the err returned is always nil, which confuses the rest of the code assuming there is no error and we have public keys.
• The other thing to check is that there is no key caching, so we're hitting the server always. We should fix that also.

[jvillafanez]

#10590 should fix the issue, although I don't think I've reproduced it correctly.

I assume the setup is that you have 2 or more OnlyOffice, so it's possible that OnlyOffice1 makes a request to the collaboration service that ends up hitting OnlyOffice2, which is down. This could explain why I don't seem to reproduce the issue with only one OnlyOffice.

Regarding the behavior, at least with one OnlyOffice, I'm getting a 404 in the web (not sure if the web team can do anything to beautify the error), but no error in the log. I guess the iframe tries to open the OnlyOffice site but it's down; this could explain why there is no logs other than a successful "openInApp" request (WOPI requests are expected to come from OnlyOffice, which is down)

[micbar]

@wkloucek are you sure about the behavior here?

I have the question what happens with the proofkeys when you restart all pods of onlyoffice?

we should not run into a situation where ocis has no keys or the wrong keys, because that would block the web office.

[wkloucek]

I assume the setup is that you have 2 or more OnlyOffice, so it's possible that OnlyOffice1 makes a request to the collaboration service that ends up hitting OnlyOffice2, which is down

No, I only have one Onlyoffice cluster that I take down (or some parts of it). I'm talking about an installation like this: https://github.com/owncloud/ocis-charts/blob/65cb136af35f7229fda2c0b045e1e9929444e199/deployments/ocis-office/helmfile.yaml#L22-L90

I have the question what happens with the proofkeys when you restart all pods of onlyoffice?

what should happen to them? They are configured in a ConfigMap, so they are the same before and after the restart if you're pointing at this. This is not yet reflected in https://github.com/owncloud/ocis-charts/tree/main/deployments/ocis-office but I can add it there, too.

we should not run into a situation where ocis has no keys or the wrong keys, because that would block the web office.

If office is down, there is no /hosting/discovery available and thus oCIS can't load the proof keys.

[micbar]

@wkloucek thanks

please note that none of us has access to the deployment repo anymore.

[jvillafanez]

From our side, the collaboration service will cache the public keys in local memory for the time period specified in the COLLABORATION_APP_PROOF_DURATION. Worst case, restarting the collaboration service should clear the cache and fetch fresh keys.
Note that this caching wasn't working before, so we were hitting the endpoint (probably) on every request.

[wkloucek]

please note that none of us has access to the deployment repo anymore.

I only linked public ocis-charts repo here (this is also no enterprise issue)

Note that this caching wasn't working before, so we were hitting the endpoint (probably) on every request.

I see that #10590 fixes it. So I could test again when it's available as a tagged (pre-)release

[jvillafanez]

Now there is a debug log entry to know when we're fetching the public keys, so it should be easy to know if it works or not.