search

owncloud / ocis

:atom_symbol: ownCloud Infinite Scale Stack
https://doc.owncloud.com/ocis/next/
Apache License 2.0
1.4k stars 182 forks source link

Ocis-wopi using nats-js-kv MICRO_REGISTRY fails to start #8104

Closed ScharfViktor closed 10 months ago

ScharfViktor commented 10 months ago

5.0.0-rc.1

Steps:

Actual: ocis_log:

2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"Starting nats-server"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Version:  2.10.7"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Git:      [not set]"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Cluster:  ocis-cluster"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Name:     NDSVSMAAEKMGP4WFQYTIHF4ARVMYR55K6LZOTFHQFNOPYNBWEKJLTLJP"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Node:     98gxHN7k"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  ID:       NDSVSMAAEKMGP4WFQYTIHF4ARVMYR55K6LZOTFHQFNOPYNBWEKJLTLJP"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"Starting JetStream"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"    _ ___ _____ ___ _____ ___ ___   _   __  __"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":" _ | | __|_   _/ __|_   _| _ \\ __| /_\\ |  \\/  |"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"| || | _|  | | \\__ \\ | | |   / _| / _ \\| |\\/| |"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":" \\__/|___| |_| |___/ |_| |_|_\\___/_/ \\_\\_|  |_|"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"         https://docs.nats.io/jetstream"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"---------------- JETSTREAM ----------------"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Max Memory:      5.82 GB"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Max Storage:     72.18 GB"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Store Directory: \"/var/lib/ocis/nats/jetstream\""}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"-------------------------------------------"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Starting restore for stream '$G > KV_service-registry'"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Restored 23 messages for stream '$G > KV_service-registry' in 1ms"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Starting restore for stream '$G > main-queue'"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Restored 99 messages for stream '$G > main-queue' in 0s"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"  Recovering 8 consumers for stream - '$G > main-queue'"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"Listening for client connections on 127.0.0.1:9233"}
2024-01-02 12:30:29 {"level":"info","service":"nats","time":"2024-01-02T11:30:29Z","line":"github.com/owncloud/ocis/v2/services/nats/pkg/logging/nats.go:21","message":"Server is ready"}
2024-01-02 12:30:35 {"level":"info","service":"app-provider","time":"2024-01-02T11:30:35Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/registry/register.go:17","message":"registering external service com.owncloud.api.app-provider-14ce8215-8fa3-4b3b-9e2a-648128ae5637@127.0.0.1:9164"}
2024-01-02 12:30:35 {"level":"info","service":"gateway","time":"2024-01-02T11:30:35Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/registry/register.go:17","message":"registering external service com.owncloud.api.gateway-5c52aa54-1e46-4048-87e1-a7c05b7ea566@172.22.0.9:9142"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/status.php","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/status","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/remote.php/dav/public-files/","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/apps/files/","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/index.php/f/","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/index.php/s/","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/remote.php/dav/ocm/","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 {"level":"info","service":"ocdav","name":"com.owncloud.web.ocdav","url":"/dav/ocm/","time":"2024-01-02T11:30:35Z","line":"github.com/cs3org/reva/v2@v2.18.0/pkg/micro/ocdav/service.go:164","message":"unprotected URL"}
2024-01-02 12:30:35 Registry nats-js-kv not found

wopi_log: 

2024-01-02 12:33:52 Failed to initialize the service: 
2024-01-02 12:33:52 
2024-01-02 12:33:52 Traceback (most recent call last):
2024-01-02 12:33:52   File "/app/core/cs3iface.py", line 47, in init
2024-01-02 12:33:52     grpc.channel_ready_future(ch).result(timeout=10)
2024-01-02 12:33:52   File "/usr/local/lib/python3.10/site-packages/grpc/_utilities.py", line 162, in result
2024-01-02 12:33:52     self._block(timeout)
2024-01-02 12:33:52   File "/usr/local/lib/python3.10/site-packages/grpc/_utilities.py", line 106, in _block
2024-01-02 12:33:52     raise grpc.FutureTimeoutError()
2024-01-02 12:33:52 grpc.FutureTimeoutError
2024-01-02 12:33:52 
2024-01-02 12:33:52 The above exception was the direct cause of the following exception:
2024-01-02 12:33:52 
2024-01-02 12:33:52 Traceback (most recent call last):
2024-01-02 12:33:52   File "/app/wopiserver.py", line 544, in <module>
2024-01-02 12:33:52     Wopi.init()
2024-01-02 12:33:52   File "/app/wopiserver.py", line 137, in init
2024-01-02 12:33:52     storage.init(cls.config, cls.log)   # initialize the storage layer
2024-01-02 12:33:52   File "/app/core/cs3iface.py", line 50, in init
2024-01-02 12:33:52     raise IOError(e) from e
2024-01-02 12:33:52 OSError
2024-01-02 12:33:31 {"time": "2024-01-02T11:33:31.089", "host": "4e06495e4fc1", "level": "ERROR", "process": "wopiserver", "module": "cs3iface", "msg": "Failed to connect to Reva via GRPC", "error": ""}
2024-01-02 12:33:31 {"time": "2024-01-02T11:33:31.090", "host": "4e06495e4fc1", "level": "CRITICAL", "process": "wopiserver", "module": "wopiserver", "msg": "Failed to initialize the service, aborting", "error": ""}
2024-01-02 12:33:41 {"time": "2024-01-02T11:33:41.653", "host": "4e06495e4fc1", "level": "ERROR", "process": "wopiserver", "module": "cs3iface", "msg": "Failed to connect to Reva via GRPC", "error": ""}
2024-01-02 12:33:41 {"time": "2024-01-02T11:33:41.654", "host": "4e06495e4fc1", "level": "CRITICAL", "process": "wopiserver", "module": "wopiserver", "msg": "Failed to initialize the service, aborting", "error": ""}
2024-01-02 12:33:52 {"time": "2024-01-02T11:33:52.222", "host": "4e06495e4fc1", "level": "ERROR", "process": "wopiserver", "module": "cs3iface", "msg": "Failed to connect to Reva via GRPC", "error": ""}
2024-01-02 12:33:52 {"time": "2024-01-02T11:33:52.223", "host": "4e06495e4fc1", "level": "CRITICAL", "process": "wopiserver", "module": "wopiserver", "msg": "Failed to initialize the service, aborting", "error": ""}

CC @kobergj

2403905 commented 10 months ago

After the fix, it works well only if two variables are set.

MICRO_REGISTRY: nats-js-kv
MICRO_REGISTRY_ADDRESS: 127.0.0.1:9233

If we set only MICRO_REGISTRY then the start fails with error

2024-01-05 17:27:35 {"level":"error","service":"webfinger","error":"Failed to connect to NATS Server: nats: no servers available for connection","transport":"http","time":"2024-01-05T16:27:35Z","line":"github.com/owncloud/ocis/v2/services/webfinger/pkg/command/server.go:97","message":"Shutting down server"}
....
2024-01-05 17:27:47 {"level":"error","service":"invitations","error":"Failed to connect to NATS Server: nats: no servers available for connection","transport":"http","time":"2024-01-08T09:07:48Z","line":"github.com/owncloud/ocis/v2/services/invitations/pkg/command/server.go:89","message":"Shutting down server"}

@kobergj Do we miss somewhere the default?

2403905 commented 10 months ago

https://github.com/owncloud/ocis/pull/8143