Update from OCIS 3.0.0 to OCIS 4.0.0 locks out OpenID users

Infinite Scale
1

We built a new ocis from the latest 4.0.0 source and are unable to access the server with any OpenID users who were previously authenticated with the 3.0.0 build running on that machine. Users who try and log in recieve an “Access denied - This could be because of a routine safety log out, or because your account is either inactive or not yet authorized for use. Please try logging in after a while or seek help from your Administrator.” message. The logs complain about inability to automatically provision the user:

Oct 01 06:38:10 ip-10-12-0-182 ocis[20620]: {“level”:“error”,“service”:“gateway”,“pkg”:“rgrpc”,“traceid”:“00000000000000000000000000000000”,“error”:“internal error: gateway: error finding an auth provider for type: bearer”,“type”:“bearer”,“time”:"2023>
Oct 01 06:38:11 ip-10-12-0-182 ocis[20620]: {“level”:“error”,“service”:“proxy”,“error”:“error authenticating service user: error authenticating user”,“time”:“2023-10-01T06:38:11Z”,“message”:“Autoprovisioning user failed”}

We don’t want new users to replace the previous ones since that would presumably lose all their files. Is there a way to have OCIS 4.0.0 simply pick up all the users that were already provisioned on the system?

2

That should be the standard behavior. We need to get some more details to figure out what is going wrong in your case. Can you share the configuration (env vars and config files) you’re using for this setup? Which IDP are you using?

Also it would be helpful to get logs of a failed login attempt with OCIS_LOG_LEVEL set to debug

3

Thanks for taking a look at this, @rhaferkamp

Here’s the current config:

OCIS_CONFIG_DIR=/etc/ocis/config
OCIS_INSECURE=false
PROXY_HTTP_ADDR=0.0.0.0:443
OCIS_URL=<redacted>
PROXY_TRANSPORT_TLS_KEY=<redacted>
PROXY_TRANSPORT_TLS_CERT=<redacted>
OCIS_LOG_LEVEL=error

# Activate s3ng storage driver
STORAGE_USERS_DRIVER=s3ng
STORAGE_USERS_S3NG_ROOT=/home/ocis/.ocis/storage/users
STORAGE_SYSTEM_DRIVER=ocis

# s3ng Wasabi S3 config
STORAGE_USERS_S3NG_ENDPOINT=<redacted>
STORAGE_USERS_S3NG_REGION=<redacted>
STORAGE_USERS_S3NG_ACCESS_KEY=<redacted>
STORAGE_USERS_S3NG_SECRET_KEY=<redacted>
STORAGE_USERS_S3NG_BUCKET=<redacted>

# OpenID
OCIS_EXCLUDE_RUN_SERVICES=idp
OCIS_OIDC_ISSUER=<redacted>
WEB_OIDC_CLIENT_ID=<redacted>
PROXY_OIDC_REWRITE_WELLKNOWN=true
PROXY_OIDC_ACCESS_TOKEN_VERIFY_METHOD=jwt
PROXY_AUTOPROVISION_ACCOUNTS=true
PROXY_USER_OIDC_CLAIM=email

# Quota defaults
OCIS_SPACES_MAX_QUOTA=0
GRAPH_SPACES_DEFAULT_QUOTA=0
FRONTEND_MAX_QUOTA=0

# Max number of concurrent go-routines
STORAGE_USERS_S3NG_MAX_CONCURRENCY=100

# Archiver limits for downloading zip/tar files
FRONTEND_ARCHIVER_MAX_NUM_FILES=10000
FRONTEND_ARCHIVER_MAX_SIZE=107374182400

# Enable asynchronous uploads with x processors
STORAGE_USERS_OCIS_ASYNC_UPLOADS=true
STORAGE_USERS_EVENTS_NUM_CONSUMERS=8

# Empty trash after 90 days
STORAGE_USERS_PURGE_TRASH_BIN_PERSONAL_DELETE_BEFORE=2160h0m0s
STORAGE_USERS_PURGE_TRASH_BIN_PROJECT_DELETE_BEFORE=2160h0m0s

And here’s the debug output from a failed attempt to connect:

Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","policy":"ocis","method":"POST","prefix":"/api/v0/settings","path":"/api/v0/settings/values-list","routeType":"prefix","time":"2023-10-06T07:44:24Z","li>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/prox>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","authenticator":"oidc","path":"/api/v0/settings/values-list","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/oidc_>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","time":"2023-10-06T07:44:24Z","line>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","time":"2023-10-06T07:44>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43288","uri":"/cs3.auth.registry.v1be>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","time":"2023-10-06T07:4>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/GetUserByClaim","time":"2023-10-06T07:44:24Z","li>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.identity.user.v1beta1.UserAPI/GetUserByClaim","time":"2023-10-06T07:44:24Z","l>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","claim":"username","value":"<redacted>","time":"2023-10-06T07:44:24Z","line":"/hom>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","backend":"ldap","basedn":"ou=users,o=libregraph-idm","filter":"(&(objectclass=inetOrgPerson)>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"idm","attrs":["displayname","ownclouduuid","mail","uid","uidNumber","gidNumber","ownCloudUserEnabled","ownCloudUserType"],"basedn":"ou=users,o=libregraph-idm",>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"idm","attrs":["displayname","ownclouduuid","mail","uid","uidNumber","gidNumber","ownCloudUserEnabled","ownCloudUserType"],"basedn":"ou=users,o=libregraph-idm",>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"error: not found: (&(objectclass=inetOrgPerson)(uid=<redacted>)(!(ownClou>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:59652","uri":"/cs3.identity.user.v1beta>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43280","uri":"/cs3.gateway.v1beta1.Ga>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","client_id":"username:<redacted>","time":"2023-10-06T07:44:24Z","line":"/ho>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:41300","uri":"/cs3.auth.provider>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43280","uri":"/cs3.gateway.v1beta1.Ga>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","claim":"email","value":"<redacted>","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/account_resolver.g>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/prox>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","time":"2023-10-06T07:44:24Z","line>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","time":"2023-10-06T07:44>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43288","uri":"/cs3.auth.registry.v1be>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-service","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","time":"2023-10-06T07:4>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-service","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:53224","uri":"/cs3.auth.provider>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43280","uri":"/cs3.gateway.v1beta1.Ga>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"error","service":"proxy","error":"error authenticating service user: error authenticating user","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middle>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"0cf72c59-5620-46d3-8cc6-7e3724d14be8","remote-addr":"114.122.168.163:60313","method":"POST","status":500,"path":"/api/v0>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"web","request-id":"","proto":"HTTP/1.1","method":"GET","status":200,"path":"/favicon.ico","duration":0.329984,"bytes":8645,"time":"2023-10-06T07:44:24Z","line">
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"ip-10-12-0-182/bqhZDaUTtC-000103","remote-addr":"114.122.168.163:60314","method":"GET","status":200,"path":"/favicon.ico>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","policy":"ocis","method":"GET","prefix":"/ocs/","path":"/ocs/v1.php/cloud/capabilities","routeType":"prefix","time":"2023-10-06T07:44:24Z","line":"/home>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"info","service":"frontend","pkg":"rhttp","traceid":"00000000000000000000000000000000","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/in>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"warn","service":"frontend","pkg":"rhttp","traceid":"00000000000000000000000000000000","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/in>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"frontend","pkg":"rhttp","traceid":"00000000000000000000000000000000","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/i>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"frontend","pkg":"rhttp","traceid":"00000000000000000000000000000000","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/i>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","time":"2023-10-06T07:44:24Z","line>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","time":"2023-10-06T07:44>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","policy":"ocis","method":"GET","prefix":"/ocs/","path":"/ocs/v1.php/cloud/user","routeType":"prefix","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43288","uri":"/cs3.auth.registry.v1be>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"error","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"internal error: gateway: error finding an auth provider for type: bearer","type":">
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43280","uri":"/cs3.gateway.v1beta1.Ga>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/prox>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","authenticator":"oidc","path":"/ocs/v1.php/cloud/user","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/oidc_auth.g>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"frontend","pkg":"rhttp","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/pkg/rhttp/rhttp.go:248","message":"http routin>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"frontend","pkg":"rhttp","traceid":"00000000000000000000000000000000","request-id":"1bd08a39-c8e0-4731-8851-a9880c94b9b1","path":"/v1.php/cloud/capabilities","t>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","time":"2023-10-06T07:44:24Z","line>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"frontend","pkg":"rhttp","traceid":"00000000000000000000000000000000","host":"127.0.0.1","method":"GET","uri":"/ocs/v1.php/cloud/capabilities?format=json","url">
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","time":"2023-10-06T07:44>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43288","uri":"/cs3.auth.registry.v1be>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"1bd08a39-c8e0-4731-8851-a9880c94b9b1","remote-addr":"114.122.168.163:60310","method":"GET","status":200,"path":"/ocs/v1.>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","time":"2023-10-06T07:4>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/GetUserByClaim","time":"2023-10-06T07:44:24Z","li>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.identity.user.v1beta1.UserAPI/GetUserByClaim","time":"2023-10-06T07:44:24Z","l>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","claim":"username","value":"<redacted>","time":"2023-10-06T07:44:24Z","line":"/hom>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","backend":"ldap","basedn":"ou=users,o=libregraph-idm","filter":"(&(objectclass=inetOrgPerson)>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"idm","attrs":["displayname","ownclouduuid","mail","uid","uidNumber","gidNumber","ownCloudUserEnabled","ownCloudUserType"],"basedn":"ou=users,o=libregraph-idm",>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"idm","attrs":["displayname","ownclouduuid","mail","uid","uidNumber","gidNumber","ownCloudUserEnabled","ownCloudUserType"],"basedn":"ou=users,o=libregraph-idm",>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"error: not found: (&(objectclass=inetOrgPerson)(uid=<redacted>)(!(ownClou>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:59652","uri":"/cs3.identity.user.v1beta>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43280","uri":"/cs3.gateway.v1beta1.Ga>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","client_id":"username:<redacted>","time":"2023-10-06T07:44:24Z","line":"/ho>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:41300","uri":"/cs3.auth.provider>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43280","uri":"/cs3.gateway.v1beta1.Ga>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","claim":"email","value":"<redacted>","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/account_resolver.g>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/prox>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","time":"2023-10-06T07:44:24Z","line>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","time":"2023-10-06T07:44>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43288","uri":"/cs3.auth.registry.v1be>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-service","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","time":"2023-10-06T07:4>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"auth-service","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:53224","uri":"/cs3.auth.provider>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:43280","uri":"/cs3.gateway.v1beta1.Ga>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"error","service":"proxy","error":"error authenticating service user: error authenticating user","time":"2023-10-06T07:44:24Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middle>
Oct 06 07:44:24 ip-10-12-0-182 ocis[82245]: {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"016e01d8-a824-458c-84c0-4633f74e0656","remote-addr":"114.122.168.163:60313","method":"GET","status":500,"path":"/ocs/v1.>
4

Unfortunately the log lines are truncated. So they’re not really helpful. Please try again. (Alternatively you could also open an issue on github and upload the file there)

5

Sorry about that. Here’s a run with full lines:

Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"storage-publiclink","service":{"name":"com.owncloud.api.storage-publiclink","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.storage-publiclink-0e6bc6a9-d2f1-4b3b-948e-90c8647d1588","address":"127.0.0.1:9178","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"frontend","service":{"name":"com.owncloud.web.frontend","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.web.frontend-72c4d856-4779-495e-9a4b-36de2cc66c81","address":"127.0.0.1:9140","metadata":{"protocol":"http","registry":"memory","server":"http","transport":"http"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"proxy","policy":"ocis","method":"GET","prefix":"/graph/","path":"/graph/v1.0/me/drives","routeType":"prefix","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/router/router.go:222","message":"director found"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"proxy","access token":{"sid":"79ad5762-ee0e-49b9-8eb5-c20c3b500654","iss":"https://sso.mycompany.com/realms/master","sub":"eeaddf70-86ad-4cb1-8a7a-cb24ef8495e7","aud":["master-realm","account"],"exp":1698733935,"iat":1696141935,"jti":"b741c1b1-9da2-4736-9ab3-7bb4133ea3ba"},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/oidc/client.go:305","message":"parsed access token"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"groups","service":{"name":"com.owncloud.api.groups","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.groups-66517a75-1cbb-4cd9-a791-44220475e267","address":"127.0.0.1:9160","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-service","service":{"name":"com.owncloud.api.auth-service","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.auth-service-61c3b5c8-fcf9-4867-9c3d-57615c364e27","address":"127.0.0.1:9199","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"storage-shares","service":{"name":"com.owncloud.api.storage-shares","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.storage-shares-4e575ea2-31d1-453f-8dfa-e5b8ebce7078","address":"127.0.0.1:9154","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"app-registry","service":{"name":"com.owncloud.api.app-registry","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.app-registry-29a708e3-52f7-4869-adf3-a620e48c224d","address":"127.0.0.1:9242","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-machine","service":{"name":"com.owncloud.api.auth-machine","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.auth-machine-1b2ede23-8c57-4df7-893f-1b34d9f423ad","address":"127.0.0.1:9166","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-basic","service":{"name":"com.owncloud.api.auth-basic","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.auth-basic-dec1a67e-08ee-403d-b894-aea3ddf45a48","address":"127.0.0.1:9146","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"users","service":{"name":"com.owncloud.api.users","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.users-6cfad606-3ac2-4de4-9b0e-8d57ab8c962f","address":"127.0.0.1:9144","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"storage-system","service":{"name":"com.owncloud.web.storage-system","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.web.storage-system-f01be6db-aa73-4c7a-ae96-25588c2988d5","address":"127.0.0.1:9216","metadata":{"protocol":"http","registry":"memory","server":"http","transport":"http"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"app-provider","service":{"name":"com.owncloud.api.app-provider","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.app-provider-8919d0f6-c271-448c-973a-c2fec6dd2500","address":"127.0.0.1:9164","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"storage-system","service":{"name":"com.owncloud.api.storage-system","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.storage-system-a9d2f231-a241-4352-aaaf-f1ac14f8d37b","address":"127.0.0.1:9215","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"storage-users","service":{"name":"com.owncloud.api.storage-users","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.storage-users-d2c4c3a0-ec48-407d-baa6-655daa958b09","address":"127.0.0.1:9157","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","service":{"name":"com.owncloud.api.gateway","version":"4.0.0+d098349d20","metadata":null,"endpoints":[],"nodes":[{"id":"com.owncloud.api.gateway-22b7ca89-2440-431d-8f41-5bc93beeebd3","address":"127.0.0.1:9142","metadata":{"protocol":"grpc","registry":"memory","server":"grpc","transport":"grpc"}}]},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/registry/register.go:30","message":"refreshing external service-registration"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"proxy","exp":"2023-10-31 06:32:15 +0000 UTC","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/oidc_auth.go:133","message":"Expiration Time from access_token"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"proxy","claims":{"aud":["master-realm","account"],"auth_time":1696141758,"azp":"xdXOt13JKxym1B1QcEncf2XDkLAexMBFwiT9j6EfhhHFJhs2KM9jbjTmf8JBXE69","email":"<redacted>","email_verified":true,"exp":1698733935,"family_name":"LastName","given_name":"FirstName","iat":1696141935,"iss":"https://sso.mycompany.com/realms/master","jti":"b741c1b1-9da2-4736-9ab3-7bb4133ea3ba","name":"FirstName LastName","preferred_username":"FirstName","realm_access":{"roles":["create-realm","default-roles-master","offline_access","admin","uma_authorization"]},"resource_access":{"account":{"roles":["manage-account","manage-account-links","view-profile"]},"master-realm":{"roles":["view-realm","view-identity-providers","manage-identity-providers","impersonation","create-client","manage-users","query-realms","view-authorization","query-clients","query-users","manage-events","manage-realm","view-events","view-users","view-clients","manage-authorization","manage-clients","query-groups"]}},"scope":"openid offline_access profile email","session_state":"79ad5762-ee0e-49b9-8eb5-c20c3b500654","sid":"79ad5762-ee0e-49b9-8eb5-c20c3b500654","sub":"eeaddf70-86ad-4cb1-8a7a-cb24ef8495e7","typ":"Bearer"},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/oidc_auth.go:123","message":"extracted claims"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"proxy","authenticator":"oidc","path":"/graph/v1.0/me/drives","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/oidc_auth.go:171","message":"successfully authenticated request"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:39776","uri":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":67211,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/GetUserByClaim","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.identity.user.v1beta1.UserAPI/GetUserByClaim","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","claim":"username","value":"<redacted>","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/pkg/user/manager/ldap/ldap.go:137","message":"GetUserByClaim"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","backend":"ldap","basedn":"ou=users,o=libregraph-idm","filter":"(&(objectclass=inetOrgPerson)(uid=<redacted>)(!(ownCloudUserEnabled=FALSE)))","scope":2,"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/pkg/utils/ldap/identity.go:217","message":"LDAP Search"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"idm","attrs":["displayname","ownclouduuid","mail","uid","uidNumber","gidNumber","ownCloudUserEnabled","ownCloudUserType"],"basedn":"ou=users,o=libregraph-idm","binddn":"uid=reva,ou=sysusers,o=libregraph-idm","filter":"(&(objectclass=inetOrgPerson)(uid=<redacted>)(!(ownCloudUserEnabled=FALSE)))","op":"search","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/log/logrus_wrapper.go:50","message":"Calling boltdb search"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"idm","attrs":["displayname","ownclouduuid","mail","uid","uidNumber","gidNumber","ownCloudUserEnabled","ownCloudUserType"],"basedn":"ou=users,o=libregraph-idm","binddn":"uid=reva,ou=sysusers,o=libregraph-idm","filter":"(&(objectclass=inetOrgPerson)(uid=<redacted>)(!(ownCloudUserEnabled=FALSE)))","op":"search","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/ocis-pkg/log/logrus_wrapper.go:50","message":"boltdb search returned 4 entries"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"error: not found: (&(objectclass=inetOrgPerson)(uid=<redacted>)(!(ownCloudUserEnabled=FALSE)))","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/pkg/user/manager/ldap/ldap.go:140","message":"GetUserByClaim"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"users","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:46330","uri":"/cs3.identity.user.v1beta1.UserAPI/GetUserByClaim","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":628187,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:39772","uri":"/cs3.gateway.v1beta1.GatewayAPI/GetUserByClaim","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":937921,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","client_id":"username:<redacted>","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/services/authprovider/authprovider.go:152","message":"unknown client id"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-machine","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:33684","uri":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":1279865,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:39772","uri":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":1942062,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"proxy","claim":"email","value":"<redacted>","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/account_resolver.go:118","message":"User by claim not found"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"proxy","claims":{"aud":["master-realm","account"],"auth_time":1696141758,"azp":"xdXOt13JKxym1B1QcEncf2XDkLAexMBFwiT9j6EfhhHFJhs2KM9jbjTmf8JBXE69","email":"<redacted>","email_verified":true,"exp":1698733935,"family_name":"LastName","given_name":"FirstName","iat":1696141935,"iss":"https://sso.mycompany.com/realms/master","jti":"b741c1b1-9da2-4736-9ab3-7bb4133ea3ba","name":"FirstName LastName","preferred_username":"FirstName","realm_access":{"roles":["create-realm","default-roles-master","offline_access","admin","uma_authorization"]},"resource_access":{"account":{"roles":["manage-account","manage-account-links","view-profile"]},"master-realm":{"roles":["view-realm","view-identity-providers","manage-identity-providers","impersonation","create-client","manage-users","query-realms","view-authorization","query-clients","query-users","manage-events","manage-realm","view-events","view-users","view-clients","manage-authorization","manage-clients","query-groups"]}},"scope":"openid offline_access profile email","session_state":"79ad5762-ee0e-49b9-8eb5-c20c3b500654","sid":"79ad5762-ee0e-49b9-8eb5-c20c3b500654","sub":"eeaddf70-86ad-4cb1-8a7a-cb24ef8495e7","typ":"Bearer"},"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/account_resolver.go:124","message":"Autoprovisioning user"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:39776","uri":"/cs3.auth.registry.v1beta1.RegistryAPI/GetAuthProviders","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":41680,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-service","pkg":"rgrpc","traceid":"00000000000000000000000000000000","method":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/auth/auth.go:122","message":"skipping auth"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"auth-service","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:37506","uri":"/cs3.auth.provider.v1beta1.ProviderAPI/Authenticate","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":56241,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"debug","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","user-agent":"grpc-go/1.58.2","from":"tcp://127.0.0.1:39772","uri":"/cs3.gateway.v1beta1.GatewayAPI/Authenticate","start":"07/Oct/2023:08:39:13 +0000","end":"07/Oct/2023:08:39:13 +0000","time_ns":600667,"code":"OK","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/vendor/github.com/cs3org/reva/v2/internal/grpc/interceptors/log/log.go:69","message":"unary"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"error","service":"proxy","error":"error authenticating service user: error authenticating user","time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/account_resolver.go:127","message":"Autoprovisioning user failed"}
Oct 07 08:39:13 ip-10-12-0-182 ocis[92597]: {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"23a93f5e-5977-43e6-8e30-0d72345f956c","remote-addr":"114.122.165.159:63585","method":"GET","status":500,"path":"/graph/v1.0/me/drives","duration":25.578589,"bytes":0,"time":"2023-10-07T08:39:13Z","line":"/home/ubuntu/ocis/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"}
6

The logs still seem to be incomplete. There should at least be some messages from the “graph” service. It’s still hard to figure out what is going wrong without those messages.

But one thing I noticed in your configuration is that you’ve set PROXY_USER_OIDC_CLAIM=email but use the default for PROXY_USER_CS3_CLAIM. Usually if you change one of those values. You need a corresponding change on the other one as well. In your case I think you’d need to set PROXY_USER_CS3_CLAIM=mail. That means that the OIDC claim email of authenticated users will be looked up against the mail attribute for auto-provisioned users in ocis.

Your current config tries to look up the mail address in the username attribute, doesn’t find that an tries to recreate the user. This does at least explain some part of the behavior you’re seeing.

If it still doesn’t work after that, we’d need the full logs of all ocis services. Also some more information on how exactly you run ocis (docker, bare-metal, …) and which IDP you’re using could be helpful.

7

Adding PROXY_USER_CS3_CLAIM=mail was all we needed - everything’s running now without any “access denied” issues. Thanks!

2 Likes
8

@rhaferkamp Thanks for your help earlier with this. But… it seems there’s still an issue with OCIS 4.0.0 with the newest config. Although access isn’t denied for existing users, all new OIDC users fail to autoprovision on OCIS and receive a “not logged in” message:

Screenshot 2023-12-10 at 13.53.01

Here’s a quick grab of the error log at the time an OIDC user who was not already provisioned on OCIS tried to access the server:

Dec 10 05:50:00 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"internal error: gateway: error finding an auth provider for type: bearer","type":"bearer","time":"2023-12-10T05:50:00Z","message":"error getting auth provider client"}
Dec 10 05:50:00 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"internal error: gateway: error finding an auth provider for type: bearer","type":"bearer","time":"2023-12-10T05:50:00Z","message":"error getting auth provider client"}
Dec 10 05:50:00 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"userlog","error":"error authenticating service user: error authenticating user","time":"2023-12-10T05:50:00Z","message":"cant get service account"}
Dec 10 05:50:16 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"proxy","error":"error authenticating service user: error authenticating user","time":"2023-12-10T05:50:16Z","message":"Autoprovisioning user failed"}
Dec 10 05:50:16 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"internal error: gateway: error finding an auth provider for type: bearer","type":"bearer","time":"2023-12-10T05:50:16Z","message":"error getting auth provider client"}
Dec 10 05:50:16 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"proxy","error":"error authenticating service user: error authenticating user","time":"2023-12-10T05:50:16Z","message":"Autoprovisioning user failed"}
Dec 10 05:50:18 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"internal error: gateway: error finding an auth provider for type: bearer","type":"bearer","time":"2023-12-10T05:50:18Z","message":"error getting auth provider client"}
Dec 10 05:50:19 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"internal error: gateway: error finding an auth provider for type: bearer","type":"bearer","time":"2023-12-10T05:50:19Z","message":"error getting auth provider client"}
Dec 10 05:50:19 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"gateway","pkg":"rgrpc","traceid":"00000000000000000000000000000000","error":"internal error: gateway: error finding an auth provider for type: bearer","type":"bearer","time":"2023-12-10T05:50:19Z","message":"error getting auth provider client"}
Dec 10 05:50:19 ip-10-12-0-182 ocis[152084]: {"level":"error","service":"userlog","error":"error authenticating service user: error authenticating user","time":"2023-12-10T05:50:19Z","message":"cant get service account"}

Maybe this is now an issue with our KeyCloak config for this client?

9

Are you sure this is a 4.0.x release? The service user is something that will come in the next release (and requires additional configuration). To me it looks like you’re a using some 5.0 prelease from the git master branch (or the :latest images)

10

Yes, it’s definitely 4.0.x:

ownCloud Infinite Scale
Edition Community
Version 4.0.0+d098349d20
Web client version 8.0.0-alpha.2
11

Hey,

i’m not 100% sure but i think this is not 4.0.x but a 5.0.0 development / alpha version because i think this is reflecting the following commit which seems to have targeted master branch.

I think this could also match the alpha version of the web client version.

13

Yeah, that was the issue… the server was built off a development branch and had some incompatibilities. We rebuilt from the v4.0.2 tag and everything works now as it should.

2 Likes