Kubernetes helm chart Failed to add user

Describe the bug

Setting up ocis v4 in a kubernetes cluster with the helm chart, and examples in the chart repo. External user management with keycloaks openldap server. Trying to log in with a new user results in errors. Trying to log in with ldap demo users fails.

Have tried with and without minio as storage.

I cannot log in with the demo users in the openldap server either. I can log in with the demo users in keycloak just fine, but not in ocis. Have tried to use different mappings for values, sub or owncloudUUID without it working.

Steps to reproduce

Steps to reproduce the behavior:

set PROXY_AUTOPROVISION_ACCOUNTS to true
create a user in keycloak with email and everything
sign in

Expected behavior

User is created, and I am signed in

Actual behavior

Lots of errors in proxy

proxy log:

``` {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"5afd9160-0954-4ec9-936f-c784b3ae7375","remote-addr":"100.64.0.3","method":"POST","status":500,"path":"/api/v0/settings/values-list","duration":326.115763,"bytes":0,"time":"2023-08-31T14:55:49.658806889Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"} {"level":"debug","service":"proxy","policy":"ocis","method":"GET","prefix":"/ocs/","path":"/ocs/v1.php/cloud/user","routeType":"prefix","time":"2023-08-31T14:55:49.667605241Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/router/router.go:222","message":"director found"} {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-08-31T14:55:49.6677239Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:67","message":"cache hit for userinfo"} {"level":"debug","service":"proxy","authenticator":"oidc","path":"/ocs/v1.php/cloud/user","time":"2023-08-31T14:55:49.667739557Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:171","message":"successfully authenticated request"} {"level":"debug","service":"proxy","claim":"sub","value":"abe5936d-7399-4c0d-a726-ea43dd39b127","time":"2023-08-31T14:55:49.676436529Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:118","message":"User by claim not found"} {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-08-31T14:55:49.67650572Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:124","message":"Autoprovisioning user"} {"level":"debug","service":"proxy","error":"not found","time":"2023-08-31T14:55:49.698775293Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/user/backend/cs3.go:211","message":"setupLibregraphClient: error during Select"} {"level":"error","service":"proxy","error":"not found","time":"2023-08-31T14:55:49.698797505Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/user/backend/cs3.go:156","message":"Error setting up libregraph client."} {"level":"error","service":"proxy","error":"not found","time":"2023-08-31T14:55:49.698803981Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:127","message":"Autoprovisioning user failed"} {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"e3f993d1-61cd-413b-ba70-49ae6fd3504c","remote-addr":"100.64.0.3","method":"GET","status":500,"path":"/ocs/v1.php/cloud/user","duration":31.263126,"bytes":0,"time":"2023-08-31T14:55:49.698826643Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"} {"level":"debug","service":"proxy","policy":"ocis","method":"POST","prefix":"/api/v0/settings","path":"/api/v0/settings/values-list","routeType":"prefix","time":"2023-08-31T14:56:39.584623355Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/router/router.go:222","message":"director found"} {"level":"debug","service":"proxy","access token":{"sid":"fee4fa70-a3b0-475e-9693-94e7bec63336","iss":"https://keycloak.bobslae.de/realms/master","sub":"abe5936d-7399-4c0d-a726-ea43dd39b127","aud":["master-realm","account"],"exp":1693493859,"iat":1693493799,"jti":"2dc8d5d9-c5ab-4808-9f75-60465b5766b7"},"time":"2023-08-31T14:56:39.587043811Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/oidc/client.go:305","message":"parsed access token"} {"level":"debug","service":"proxy","exp":"2023-08-31 14:57:39 +0000 UTC","time":"2023-08-31T14:56:39.67946274Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:133","message":"Expiration Time from access_token"} {"level":"debug","service":"proxy","claims":{"acr":"1","allowed-origins":["*"],"aud":["master-realm","account"],"auth_time":1693493648,"azp":"ocis-web","email":"jeppe.dyrby+foo@gmail.com","email_verified":true,"exp":1693493859,"family_name":"Bar","given_name":"Foo","iat":1693493799,"iss":"https://keycloak.bobslae.de/realms/master","jti":"2dc8d5d9-c5ab-4808-9f75-60465b5766b7","name":"Foo Bar","preferred_username":"foo","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-identity-providers","view-realm","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 profile ownCloudUUID email","session_state":"fee4fa70-a3b0-475e-9693-94e7bec63336","sid":"fee4fa70-a3b0-475e-9693-94e7bec63336","sub":"abe5936d-7399-4c0d-a726-ea43dd39b127","typ":"Bearer"},"time":"2023-08-31T14:56:39.679532111Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:123","message":"extracted claims"} {"level":"debug","service":"proxy","authenticator":"oidc","path":"/api/v0/settings/values-list","time":"2023-08-31T14:56:39.67954161Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:171","message":"successfully authenticated request"} {"level":"debug","service":"proxy","claim":"sub","value":"abe5936d-7399-4c0d-a726-ea43dd39b127","time":"2023-08-31T14:56:39.900953442Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:118","message":"User by claim not found"} {"level":"debug","service":"proxy","claims":{"acr":"1","allowed-origins":["*"],"aud":["master-realm","account"],"auth_time":1693493648,"azp":"ocis-web","email":"jeppe.dyrby+foo@gmail.com","email_verified":true,"exp":1693493859,"family_name":"Bar","given_name":"Foo","iat":1693493799,"iss":"https://keycloak.bobslae.de/realms/master","jti":"2dc8d5d9-c5ab-4808-9f75-60465b5766b7","name":"Foo Bar","preferred_username":"foo","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-identity-providers","view-realm","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 profile ownCloudUUID email","session_state":"fee4fa70-a3b0-475e-9693-94e7bec63336","sid":"fee4fa70-a3b0-475e-9693-94e7bec63336","sub":"abe5936d-7399-4c0d-a726-ea43dd39b127","typ":"Bearer"},"time":"2023-08-31T14:56:39.901190205Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:124","message":"Autoprovisioning user"} {"level":"debug","service":"proxy","error":"not found","time":"2023-08-31T14:56:39.944484368Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/user/backend/cs3.go:211","message":"setupLibregraphClient: error during Select"} {"level":"error","service":"proxy","error":"not found","time":"2023-08-31T14:56:39.944557106Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/user/backend/cs3.go:156","message":"Error setting up libregraph client."} {"level":"error","service":"proxy","error":"not found","time":"2023-08-31T14:56:39.944578359Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:127","message":"Autoprovisioning user failed"} {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"d2aa83d2-5721-44f0-ae97-fbb9ec2f971a","remote-addr":"100.64.0.3","method":"POST","status":500,"path":"/api/v0/settings/values-list","duration":360.180229,"bytes":0,"time":"2023-08-31T14:56:39.944650221Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"} {"level":"debug","service":"proxy","policy":"ocis","method":"GET","prefix":"/ocs/","path":"/ocs/v1.php/cloud/user","routeType":"prefix","time":"2023-08-31T14:56:39.968817229Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/router/router.go:222","message":"director found"} {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-08-31T14:56:39.969215298Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:67","message":"cache hit for userinfo"} {"level":"debug","service":"proxy","authenticator":"oidc","path":"/ocs/v1.php/cloud/user","time":"2023-08-31T14:56:39.969268678Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:171","message":"successfully authenticated request"} {"level":"debug","service":"proxy","claim":"sub","value":"abe5936d-7399-4c0d-a726-ea43dd39b127","time":"2023-08-31T14:56:39.994978145Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:118","message":"User by claim not found"} {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-08-31T14:56:39.995193649Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:124","message":"Autoprovisioning user"} {"level":"debug","service":"proxy","error":"not found","time":"2023-08-31T14:56:40.106461163Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/user/backend/cs3.go:211","message":"setupLibregraphClient: error during Select"} {"level":"error","service":"proxy","error":"not found","time":"2023-08-31T14:56:40.106481764Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/user/backend/cs3.go:156","message":"Error setting up libregraph client."} {"level":"error","service":"proxy","error":"not found","time":"2023-08-31T14:56:40.106489487Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:127","message":"Autoprovisioning user failed"} {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"38a5b315-5a42-45f1-a054-484d0cb26a07","remote-addr":"100.64.0.3","method":"GET","status":500,"path":"/ocs/v1.php/cloud/user","duration":137.859088,"bytes":0,"time":"2023-08-31T14:56:40.106518844Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"} ```

graph log

``` {"level":"debug","service":"graph","allowed_origins":"*","allowed_methods":"GET, POST, PUT, PATCH, DELETE, OPTIONS","allowed_headers":"Authorization, Origin, Content-Type, Accept, X-Requested-With, X-Request-Id, Purge, Restore","allow_credentials":true,"time":"2023-08-31T14:59:19.40624157Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/header.go:33","message":"setup cors middleware"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/applications/","middlewares":8,"time":"2023-08-31T14:59:19.406952243Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/applications/{applicationID}","middlewares":8,"time":"2023-08-31T14:59:19.406969936Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/drives/","middlewares":8,"time":"2023-08-31T14:59:19.407029197Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/drives/","middlewares":8,"time":"2023-08-31T14:59:19.4070347Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/drives/{driveID}/","middlewares":8,"time":"2023-08-31T14:59:19.407043226Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"PATCH","route":"/graph/v1.0/drives/{driveID}/","middlewares":8,"time":"2023-08-31T14:59:19.40704904Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/drives/{driveID}/","middlewares":8,"time":"2023-08-31T14:59:19.407054565Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/classes/","middlewares":8,"time":"2023-08-31T14:59:19.407103764Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/education/classes/","middlewares":8,"time":"2023-08-31T14:59:19.40710924Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/education/classes/{classID}/","middlewares":8,"time":"2023-08-31T14:59:19.407183345Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"PATCH","route":"/graph/v1.0/education/classes/{classID}/","middlewares":8,"time":"2023-08-31T14:59:19.407188978Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/classes/{classID}/","middlewares":8,"time":"2023-08-31T14:59:19.407194175Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/classes/{classID}/members/","middlewares":8,"time":"2023-08-31T14:59:19.407211964Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/education/classes/{classID}/members/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407218907Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/education/classes/{classID}/members/{memberID}/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407225265Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/classes/{classID}/teachers/","middlewares":8,"time":"2023-08-31T14:59:19.407240492Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/education/classes/{classID}/teachers/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407247236Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/education/classes/{classID}/teachers/{teacherID}/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407253105Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/schools/","middlewares":8,"time":"2023-08-31T14:59:19.407273707Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/education/schools/","middlewares":8,"time":"2023-08-31T14:59:19.407279459Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/education/schools/{schoolID}/","middlewares":8,"time":"2023-08-31T14:59:19.407304614Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"PATCH","route":"/graph/v1.0/education/schools/{schoolID}/","middlewares":8,"time":"2023-08-31T14:59:19.407309814Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/schools/{schoolID}/","middlewares":8,"time":"2023-08-31T14:59:19.40731536Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/schools/{schoolID}/classes/","middlewares":8,"time":"2023-08-31T14:59:19.407330386Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/education/schools/{schoolID}/classes/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407336116Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/education/schools/{schoolID}/classes/{classID}/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407341891Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/schools/{schoolID}/users/","middlewares":8,"time":"2023-08-31T14:59:19.407352445Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/education/schools/{schoolID}/users/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407358591Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/education/schools/{schoolID}/users/{userID}/$ref","middlewares":8,"time":"2023-08-31T14:59:19.407364585Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/users/","middlewares":8,"time":"2023-08-31T14:59:19.407393376Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/education/users/","middlewares":8,"time":"2023-08-31T14:59:19.407400622Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/education/users/{userID}/","middlewares":8,"time":"2023-08-31T14:59:19.407408961Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/education/users/{userID}/","middlewares":8,"time":"2023-08-31T14:59:19.407415268Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"PATCH","route":"/graph/v1.0/education/users/{userID}/","middlewares":8,"time":"2023-08-31T14:59:19.407420536Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/extensions/org.libregraph/tags","middlewares":8,"time":"2023-08-31T14:59:19.407429028Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/extensions/org.libregraph/tags","middlewares":8,"time":"2023-08-31T14:59:19.407435419Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"PUT","route":"/graph/v1.0/extensions/org.libregraph/tags","middlewares":8,"time":"2023-08-31T14:59:19.407440737Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/groups/","middlewares":9,"time":"2023-08-31T14:59:19.407459345Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/groups/","middlewares":9,"time":"2023-08-31T14:59:19.407464667Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"PATCH","route":"/graph/v1.0/groups/{groupID}/","middlewares":9,"time":"2023-08-31T14:59:19.407483208Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/groups/{groupID}/","middlewares":8,"time":"2023-08-31T14:59:19.40748838Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/groups/{groupID}/","middlewares":9,"time":"2023-08-31T14:59:19.407493781Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/groups/{groupID}/members/","middlewares":9,"time":"2023-08-31T14:59:19.407507615Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/groups/{groupID}/members/$ref","middlewares":9,"time":"2023-08-31T14:59:19.407513291Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/groups/{groupID}/members/{memberID}/$ref","middlewares":9,"time":"2023-08-31T14:59:19.40751912Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/me/","middlewares":8,"time":"2023-08-31T14:59:19.407535358Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/me/changePassword","middlewares":8,"time":"2023-08-31T14:59:19.407541461Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/me/drive","middlewares":8,"time":"2023-08-31T14:59:19.407547191Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/me/drive/root/children","middlewares":8,"time":"2023-08-31T14:59:19.407557143Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/me/drives","middlewares":8,"time":"2023-08-31T14:59:19.407563184Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/users/","middlewares":9,"time":"2023-08-31T14:59:19.407588946Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/users/","middlewares":9,"time":"2023-08-31T14:59:19.407594847Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"PATCH","route":"/graph/v1.0/users/{userID}/","middlewares":9,"time":"2023-08-31T14:59:19.407622168Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/users/{userID}/","middlewares":8,"time":"2023-08-31T14:59:19.407627601Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/users/{userID}/","middlewares":9,"time":"2023-08-31T14:59:19.407633426Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/users/{userID}/appRoleAssignments/","middlewares":8,"time":"2023-08-31T14:59:19.407642893Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/users/{userID}/appRoleAssignments/","middlewares":8,"time":"2023-08-31T14:59:19.407649252Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"DELETE","route":"/graph/v1.0/users/{userID}/appRoleAssignments/{appRoleAssignmentID}","middlewares":8,"time":"2023-08-31T14:59:19.407655453Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"GET","route":"/graph/v1.0/users/{userID}/drive","middlewares":8,"time":"2023-08-31T14:59:19.407661299Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","method":"POST","route":"/graph/v1.0/users/{userID}/exportPersonalData","middlewares":8,"time":"2023-08-31T14:59:19.407667101Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/service.go:310","message":"serving endpoint"} {"level":"debug","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000001","time":"2023-08-31T14:59:28.462615944Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:256","message":"calling create user"} {"level":"debug","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000001","user":{"displayName":"Foo Bar","mail":"jeppe.dyrby+foo@gmail.com","onPremisesSamAccountName":"foo","userType":"Member"},"time":"2023-08-31T14:59:28.462774758Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:309","message":"calling create user on backend"} {"level":"debug","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000001","backend":"ldap","time":"2023-08-31T14:59:28.462787425Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:178","message":"CreateUser"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.462809789Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:265","message":"LDAP connection reset"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.462819305Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:224","message":"reconnecting to LDAP"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.462839287Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:235","message":"Connecting to ldap://openldap.home-cloud.svc.cluster.local"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.462904419Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:267","message":"Waiting for new connection"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.465123609Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:248","message":"LDAP Connected"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.465138247Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:250","message":"Binding as cn=admin,dc=owncloud,dc=com"} {"level":"error","service":"graph","error":"LDAP Result Code 49 \"Invalid Credentials\": ","time":"2023-08-31T14:59:28.46558648Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:253","message":"Bind failed"} {"level":"error","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000001","error":"LDAP Result Code 49 \"Invalid Credentials\": ","time":"2023-08-31T14:59:28.465656445Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:194","message":"failed to add user"} {"level":"error","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000001","error":"generalException","time":"2023-08-31T14:59:28.465676751Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:311","message":"could not create user: backend error"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"POST","status":500,"path":"/graph/v1.0/users","duration":33.85671,"bytes":170,"time":"2023-08-31T14:59:28.465750728Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000002","time":"2023-08-31T14:59:28.576293266Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:256","message":"calling create user"} {"level":"debug","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000002","user":{"displayName":"Foo Bar","mail":"jeppe.dyrby+foo@gmail.com","onPremisesSamAccountName":"foo","userType":"Member"},"time":"2023-08-31T14:59:28.576502185Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:309","message":"calling create user on backend"} {"level":"debug","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000002","backend":"ldap","time":"2023-08-31T14:59:28.576560629Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:178","message":"CreateUser"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.576661967Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:265","message":"LDAP connection reset"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.576702214Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:224","message":"reconnecting to LDAP"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.576731174Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:235","message":"Connecting to ldap://openldap.home-cloud.svc.cluster.local"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.576931288Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:267","message":"Waiting for new connection"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.586353206Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:248","message":"LDAP Connected"} {"level":"debug","service":"graph","time":"2023-08-31T14:59:28.586397125Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:250","message":"Binding as cn=admin,dc=owncloud,dc=com"} {"level":"error","service":"graph","error":"LDAP Result Code 49 \"Invalid Credentials\": ","time":"2023-08-31T14:59:28.587860192Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:253","message":"Bind failed"} {"level":"error","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000002","error":"LDAP Result Code 49 \"Invalid Credentials\": ","time":"2023-08-31T14:59:28.588110134Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:194","message":"failed to add user"} {"level":"error","service":"graph","request-id":"graph-6499fbdb8f-4fcrs/DzsNLbWgtl-000002","error":"generalException","time":"2023-08-31T14:59:28.588192748Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:311","message":"could not create user: backend error"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"POST","status":500,"path":"/graph/v1.0/users","duration":14.854828,"bytes":170,"time":"2023-08-31T14:59:28.588350775Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} ```

Setup

Using helm chart from repo. Have added demo users to ldap server.

Additional context

Add any other context about the problem here.

I have gotten my ocis connected to LDAP.
When I try to sign in with a new user from keycloak, I get the following in the proxy log:

``` {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"a63cd945006624bbdf4e3ca5863579e2","remote-addr":"100.64.0.3","method":"GET","status":200,"path":"/themes/owncloud/assets/favicon.jpg","duration":2.949718,"bytes":615,"time":"2023-09-01T08:05:32.737991602Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"} {"level":"debug","service":"proxy","policy":"ocis","method":"POST","prefix":"/api/v0/settings","path":"/api/v0/settings/values-list","routeType":"prefix","time":"2023-09-01T08:05:32.801063777Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/router/router.go:222","message":"director found"} {"level":"debug","service":"proxy","access token":{"sid":"cc70b012-ead2-4d61-ab61-458cdef4723f","iss":"https://keycloak.bobslae.de/realms/master","sub":"4ac1f595-190e-4a95-84eb-436c479b234d","aud":["account"],"exp":1693555592,"iat":1693555532,"jti":"055a9fce-dd56-4c75-b04c-36a97730443b"},"time":"2023-09-01T08:05:32.805504636Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/oidc/client.go:305","message":"parsed access token"} {"level":"debug","service":"proxy","exp":"2023-09-01 08:06:32 +0000 UTC","time":"2023-09-01T08:05:32.924509574Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:133","message":"Expiration Time from access_token"} {"level":"debug","service":"proxy","claims":{"acr":"1","allowed-origins":["*"],"aud":"account","auth_time":1693555531,"azp":"ocis-web","email":"jeppe.dyrby@gmail.com","email_verified":true,"exp":1693555592,"family_name":"Dyrby","given_name":"Jeppe","iat":1693555532,"iss":"https://keycloak.bobslae.de/realms/master","jti":"055a9fce-dd56-4c75-b04c-36a97730443b","name":"Jeppe Dyrby","preferred_username":"jeppe","realm_access":{"roles":["default-roles-master","offline_access","uma_authorization"]},"resource_access":{"account":{"roles":["manage-account","manage-account-links","view-profile"]}},"scope":"openid profile ownCloudUUID email","session_state":"cc70b012-ead2-4d61-ab61-458cdef4723f","sid":"cc70b012-ead2-4d61-ab61-458cdef4723f","sub":"4ac1f595-190e-4a95-84eb-436c479b234d","typ":"Bearer"},"time":"2023-09-01T08:05:32.925623711Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:123","message":"extracted claims"} {"level":"debug","service":"proxy","authenticator":"oidc","path":"/api/v0/settings/values-list","time":"2023-09-01T08:05:32.925751073Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:171","message":"successfully authenticated request"} {"level":"debug","service":"proxy","claim":"email","value":"jeppe.dyrby@gmail.com","time":"2023-09-01T08:05:33.325667701Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:118","message":"User by claim not found"} {"level":"debug","service":"proxy","claims":{"acr":"1","allowed-origins":["*"],"aud":"account","auth_time":1693555531,"azp":"ocis-web","email":"jeppe.dyrby@gmail.com","email_verified":true,"exp":1693555592,"family_name":"Dyrby","given_name":"Jeppe","iat":1693555532,"iss":"https://keycloak.bobslae.de/realms/master","jti":"055a9fce-dd56-4c75-b04c-36a97730443b","name":"Jeppe Dyrby","preferred_username":"jeppe","realm_access":{"roles":["default-roles-master","offline_access","uma_authorization"]},"resource_access":{"account":{"roles":["manage-account","manage-account-links","view-profile"]}},"scope":"openid profile ownCloudUUID email","session_state":"cc70b012-ead2-4d61-ab61-458cdef4723f","sid":"cc70b012-ead2-4d61-ab61-458cdef4723f","sub":"4ac1f595-190e-4a95-84eb-436c479b234d","typ":"Bearer"},"time":"2023-09-01T08:05:33.32585793Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:124","message":"Autoprovisioning user"} 2023/09/01 08:05:33 http: panic serving 10.1.0.4:36198: runtime error: invalid memory address or nil pointer dereference goroutine 9652 [running]: net/http.(*conn).serve.func1() net/http/server.go:1854 +0xbf panic({0x3ff9820, 0x5df2ce0}) runtime/panic.go:890 +0x263 github.com/owncloud/ocis/v2/services/proxy/pkg/middleware.accountResolver.ServeHTTP({{0x4534c80, 0xc00097b360}, {{{0x4545488, 0xc001373340}, 0x0, {0x0, 0x0}, {0xc000411800, 0x12, 0x1f4}, ...}}, ...}, ...) github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:133 +0x9d5 github.com/owncloud/ocis/v2/services/proxy/pkg/middleware.Authentication.func1.1({0x7f9eed9ff848, 0xc001f06980}, 0xc001651000) github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/authentication.go:74 +0x45c net/http.HandlerFunc.ServeHTTP(0x4552a48?, {0x7f9eed9ff848?, 0xc001f06980?}, 0x60b64b0?) net/http/server.go:2122 +0x2f github.com/owncloud/ocis/v2/services/proxy/pkg/router.Middleware.func1.1({0x7f9eed9ff848, 0xc001f06980}, 0xc001650f00) github.com/owncloud/ocis/v2/services/proxy/pkg/router/router.go:31 +0x20e net/http.HandlerFunc.ServeHTTP(0xc001c4d085?, {0x7f9eed9ff848?, 0xc001f06980?}, 0xc000b08ee0?) net/http/server.go:2122 +0x2f github.com/owncloud/ocis/v2/services/proxy/pkg/middleware.OIDCWellKnownRewrite.func1.1({0x7f9eed9ff848, 0xc001f06980}, 0xc001650f00?) github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_well-known.go:45 +0x313 net/http.HandlerFunc.ServeHTTP(0xc0020fda40?, {0x7f9eed9ff848?, 0xc001f06980?}, 0xd04dc5?) net/http/server.go:2122 +0x2f github.com/owncloud/ocis/v2/services/proxy/pkg/middleware.HTTPSRedirect.func1({0x7f9eed9ff848, 0xc001f06980}, 0xc001650f00) github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/https_redirect.go:17 +0x142 net/http.HandlerFunc.ServeHTTP(0x4552310?, {0x7f9eed9ff848?, 0xc001f06980?}, 0xc?) net/http/server.go:2122 +0x2f github.com/owncloud/ocis/v2/services/proxy/pkg/middleware.AccessLog.func1.1({0x4552310, 0xc0017d8a80}, 0xc001650f00) github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:20 +0x1e7 net/http.HandlerFunc.ServeHTTP(0x4552a48?, {0x4552310?, 0xc0017d8a80?}, 0x3c3d5f0?) net/http/server.go:2122 +0x2f github.com/go-chi/chi/v5/middleware.RequestID.func1({0x4552310, 0xc0017d8a80}, 0xc001650e00) github.com/go-chi/chi/v5@v5.0.10/middleware/request_id.go:76 +0x22d net/http.HandlerFunc.ServeHTTP(0xc001650e00?, {0x4552310?, 0xc0017d8a80?}, 0xc000103000?) net/http/server.go:2122 +0x2f github.com/go-chi/chi/v5/middleware.RealIP.func1({0x4552310, 0xc0017d8a80}, 0xc001650e00) github.com/go-chi/chi/v5@v5.0.10/middleware/realip.go:36 +0x9e net/http.HandlerFunc.ServeHTTP(0x100?, {0x4552310?, 0xc0017d8a80?}, 0x4551860?) net/http/server.go:2122 +0x2f github.com/owncloud/ocis/v2/ocis-pkg/middleware.TraceContext.func1({0x4552310, 0xc0017d8a80}, 0xc001650d00) github.com/owncloud/ocis/v2/ocis-pkg/middleware/tracing.go:19 +0x184 net/http.HandlerFunc.ServeHTTP(0x4552a48?, {0x4552310?, 0xc0017d8a80?}, 0x4551860?) net/http/server.go:2122 +0x2f github.com/owncloud/ocis/v2/services/proxy/pkg/middleware.tracer.ServeHTTP({{0x453c560?, 0xc001345560?}, {0x453b840?, 0x60b64b0?}}, {0x4552310, 0xc0017d8a80}, 0xc001650c00) github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/tracing.go:50 +0x482 go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*middleware).serveHTTP(0xc0004efe40, {0x454fe50?, 0xc0010730a0}, 0xc001650b00, {0x4534ca0, 0xc001361a60}) go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp@v0.42.1-0.20230608065455-5cc3715df180/handler.go:217 +0x122e go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.NewMiddleware.func1.1({0x454fe50?, 0xc0010730a0?}, 0xc000b09ad0?) go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp@v0.42.1-0.20230608065455-5cc3715df180/handler.go:81 +0x3b net/http.HandlerFunc.ServeHTTP(0x0?, {0x454fe50?, 0xc0010730a0?}, 0x731b14?) net/http/server.go:2122 +0x2f net/http.serverHandler.ServeHTTP({0x4543f20?}, {0x454fe50, 0xc0010730a0}, 0xc001650b00) net/http/server.go:2936 +0x316 net/http.(*conn).serve(0xc001816000, {0x4552a48, 0xc000649320}) net/http/server.go:1995 +0x612 created by net/http.(*Server).Serve net/http/server.go:3089 +0x5ed {"level":"debug","service":"proxy","policy":"ocis","method":"GET","prefix":"/ocs/","path":"/ocs/v1.php/cloud/capabilities","routeType":"prefix","time":"2023-09-01T08:05:33.870872731Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/router/router.go:222","message":"director found"} {"level":"debug","service":"proxy","policy":"ocis","method":"GET","prefix":"/ocs/","path":"/ocs/v1.php/cloud/user","routeType":"prefix","time":"2023-09-01T08:05:33.871497339Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/router/router.go:222","message":"director found"} {"level":"debug","service":"proxy","claims":"marshaling error: json: unsupported type: map[interface {}]interface {}","time":"2023-09-01T08:05:33.872052379Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:67","message":"cache hit for userinfo"} {"level":"debug","service":"proxy","authenticator":"oidc","path":"/ocs/v1.php/cloud/user","time":"2023-09-01T08:05:33.872130372Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/oidc_auth.go:171","message":"successfully authenticated request"} {"level":"debug","service":"proxy","time":"2023-09-01T08:05:33.88573357Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/userroles/oidcroles.go:162","message":"refreshing roles ids"} {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"863a240c-0335-469e-8788-841bc71d53f9","remote-addr":"100.64.0.3","method":"GET","status":200,"path":"/ocs/v1.php/cloud/capabilities","duration":110.871303,"bytes":2497,"time":"2023-09-01T08:05:33.981497952Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"} {"level":"debug","service":"proxy","role":"spaceadmin","id":"2aadd357-682c-406b-8874-293091995fdd","time":"2023-09-01T08:05:33.994134902Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/userroles/oidcroles.go:192","message":"Got Role"} {"level":"debug","service":"proxy","role":"user-light","id":"38071a68-456a-4553-846a-fa67bf5596cc","time":"2023-09-01T08:05:33.994160476Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/userroles/oidcroles.go:192","message":"Got Role"} {"level":"debug","service":"proxy","role":"admin","id":"71881883-1768-46bd-a24d-a356a2afdf7f","time":"2023-09-01T08:05:33.9941935Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/userroles/oidcroles.go:192","message":"Got Role"} {"level":"debug","service":"proxy","role":"user","id":"d7beeea8-8ff4-406b-8fb6-ab2dd81e6b11","time":"2023-09-01T08:05:33.994218703Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/userroles/oidcroles.go:192","message":"Got Role"} {"level":"debug","service":"proxy","roleMap":{"admin":"71881883-1768-46bd-a24d-a356a2afdf7f","spaceadmin":"2aadd357-682c-406b-8874-293091995fdd","user":"d7beeea8-8ff4-406b-8fb6-ab2dd81e6b11","user-light":"38071a68-456a-4553-846a-fa67bf5596cc"},"time":"2023-09-01T08:05:33.994241962Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/userroles/oidcroles.go:195","message":"Role Name to role ID map"} {"level":"error","service":"proxy","request-id":"fc53a17f-71ae-49b2-97b3-35c2c7b01992","userid":"372496c5-c33c-47a7-8baf-c8c7fc37b7d5","rolesClaim":"roles","time":"2023-09-01T08:05:33.994298716Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/userroles/oidcroles.go:45","message":"No roles in user claims"} {"level":"error","service":"proxy","error":"no roles in user claims","time":"2023-09-01T08:05:33.994312599Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/account_resolver.go:154","message":"Could not get user roles"} {"level":"info","service":"proxy","proto":"HTTP/1.1","request-id":"fc53a17f-71ae-49b2-97b3-35c2c7b01992","remote-addr":"100.64.0.3","method":"GET","status":500,"path":"/ocs/v1.php/cloud/user","duration":123.077581,"bytes":0,"time":"2023-09-01T08:05:33.994338709Z","line":"github.com/owncloud/ocis/v2/services/proxy/pkg/middleware/accesslog.go:31","message":"access-log"} ```

and from the graph log:

``` {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035347","time":"2023-09-01T08:04:23.007256872Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:256","message":"calling create user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035347","user":{"displayName":"Jeppe Dyrby","mail":"jeppe.dyrby@gmail.com","onPremisesSamAccountName":"jeppe","userType":"Member"},"time":"2023-09-01T08:04:23.007323658Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:309","message":"calling create user on backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035347","backend":"ldap","time":"2023-09-01T08:04:23.007339813Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:178","message":"CreateUser"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.007362389Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035347","error":"LDAP Result Code 68 \"Entry Already Exists\": ","time":"2023-09-01T08:04:23.007795896Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:194","message":"failed to add user"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035347","error":"nameAlreadyExists","time":"2023-09-01T08:04:23.007814467Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:311","message":"could not create user: backend error"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"POST","status":409,"path":"/graph/v1.0/users","duration":3.249175,"bytes":189,"time":"2023-09-01T08:04:23.007902976Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035348","time":"2023-09-01T08:04:23.008397885Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:344","message":"calling get user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035348","id":"jeppe","time":"2023-09-01T08:04:23.008416452Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:376","message":"calling get user from backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035348","backend":"ldap","time":"2023-09-01T08:04:23.008430745Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:531","message":"GetUser"} {"level":"debug","service":"graph","backend":"ldap","base":"ou=users,dc=owncloud,dc=com","filter":"(&(objectClass=inetOrgPerson)(|(uid=jeppe)(uid=jeppe)))","scope":2,"sizelimit":1,"attributes":["displayname","uid","mail","uid","sn","givenname","ownCloudUserEnabled","ownCloudUserType"],"time":"2023-09-01T08:04:23.00845139Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:459","message":"getEntryByFilter"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.008466539Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"GET","status":200,"path":"/graph/v1.0/users/jeppe","duration":0.663394,"bytes":64,"time":"2023-09-01T08:04:23.008969441Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035349","time":"2023-09-01T08:04:23.109153292Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:256","message":"calling create user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035349","user":{"displayName":"Jeppe Dyrby","mail":"jeppe.dyrby@gmail.com","onPremisesSamAccountName":"jeppe","userType":"Member"},"time":"2023-09-01T08:04:23.10943079Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:309","message":"calling create user on backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035349","backend":"ldap","time":"2023-09-01T08:04:23.1096206Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:178","message":"CreateUser"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.109771283Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035349","error":"LDAP Result Code 68 \"Entry Already Exists\": ","time":"2023-09-01T08:04:23.111849095Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:194","message":"failed to add user"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035349","error":"nameAlreadyExists","time":"2023-09-01T08:04:23.112193486Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:311","message":"could not create user: backend error"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"POST","status":409,"path":"/graph/v1.0/users","duration":10.523961,"bytes":189,"time":"2023-09-01T08:04:23.112642305Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035350","time":"2023-09-01T08:04:23.115246844Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:344","message":"calling get user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035350","id":"jeppe","time":"2023-09-01T08:04:23.115322412Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:376","message":"calling get user from backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035350","backend":"ldap","time":"2023-09-01T08:04:23.11538117Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:531","message":"GetUser"} {"level":"debug","service":"graph","backend":"ldap","base":"ou=users,dc=owncloud,dc=com","filter":"(&(objectClass=inetOrgPerson)(|(uid=jeppe)(uid=jeppe)))","scope":2,"sizelimit":1,"attributes":["displayname","uid","mail","uid","sn","givenname","ownCloudUserEnabled","ownCloudUserType"],"time":"2023-09-01T08:04:23.115464241Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:459","message":"getEntryByFilter"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.115577515Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"GET","status":200,"path":"/graph/v1.0/users/jeppe","duration":3.681236,"bytes":64,"time":"2023-09-01T08:04:23.118541094Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035351","time":"2023-09-01T08:04:23.145756539Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:256","message":"calling create user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035351","user":{"displayName":"Jeppe Dyrby","mail":"jeppe.dyrby@gmail.com","onPremisesSamAccountName":"jeppe","userType":"Member"},"time":"2023-09-01T08:04:23.146267179Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:309","message":"calling create user on backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035351","backend":"ldap","time":"2023-09-01T08:04:23.146601441Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:178","message":"CreateUser"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.147075739Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035351","error":"LDAP Result Code 68 \"Entry Already Exists\": ","time":"2023-09-01T08:04:23.150176695Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:194","message":"failed to add user"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035351","error":"nameAlreadyExists","time":"2023-09-01T08:04:23.15029246Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:311","message":"could not create user: backend error"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"POST","status":409,"path":"/graph/v1.0/users","duration":18.21585,"bytes":189,"time":"2023-09-01T08:04:23.151351513Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035352","time":"2023-09-01T08:04:23.157085151Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:344","message":"calling get user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035352","id":"jeppe","time":"2023-09-01T08:04:23.157755319Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:376","message":"calling get user from backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035352","backend":"ldap","time":"2023-09-01T08:04:23.158040597Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:531","message":"GetUser"} {"level":"debug","service":"graph","backend":"ldap","base":"ou=users,dc=owncloud,dc=com","filter":"(&(objectClass=inetOrgPerson)(|(uid=jeppe)(uid=jeppe)))","scope":2,"sizelimit":1,"attributes":["displayname","uid","mail","uid","sn","givenname","ownCloudUserEnabled","ownCloudUserType"],"time":"2023-09-01T08:04:23.158552387Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:459","message":"getEntryByFilter"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.158709305Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"GET","status":200,"path":"/graph/v1.0/users/jeppe","duration":7.063928,"bytes":64,"time":"2023-09-01T08:04:23.163693324Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035353","time":"2023-09-01T08:04:23.206324932Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:256","message":"calling create user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035353","user":{"displayName":"Jeppe Dyrby","mail":"jeppe.dyrby@gmail.com","onPremisesSamAccountName":"jeppe","userType":"Member"},"time":"2023-09-01T08:04:23.206622201Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:309","message":"calling create user on backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035353","backend":"ldap","time":"2023-09-01T08:04:23.206719856Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:178","message":"CreateUser"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.207175012Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035353","error":"LDAP Result Code 68 \"Entry Already Exists\": ","time":"2023-09-01T08:04:23.210547593Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:194","message":"failed to add user"} {"level":"error","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035353","error":"nameAlreadyExists","time":"2023-09-01T08:04:23.210737857Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:311","message":"could not create user: backend error"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"POST","status":409,"path":"/graph/v1.0/users","duration":19.138034,"bytes":189,"time":"2023-09-01T08:04:23.211232827Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035354","time":"2023-09-01T08:04:23.215099665Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:344","message":"calling get user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035354","id":"jeppe","time":"2023-09-01T08:04:23.215212149Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:376","message":"calling get user from backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035354","backend":"ldap","time":"2023-09-01T08:04:23.215290448Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:531","message":"GetUser"} {"level":"debug","service":"graph","backend":"ldap","base":"ou=users,dc=owncloud,dc=com","filter":"(&(objectClass=inetOrgPerson)(|(uid=jeppe)(uid=jeppe)))","scope":2,"sizelimit":1,"attributes":["displayname","uid","mail","uid","sn","givenname","ownCloudUserEnabled","ownCloudUserType"],"time":"2023-09-01T08:04:23.215389854Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:459","message":"getEntryByFilter"} {"level":"debug","service":"graph","time":"2023-09-01T08:04:23.215485298Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"GET","status":200,"path":"/graph/v1.0/users/jeppe","duration":4.703482,"bytes":64,"time":"2023-09-01T08:04:23.218809017Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035359","time":"2023-09-01T08:05:33.4084239Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:256","message":"calling create user"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035359","user":{"displayName":"Jeppe Dyrby","mail":"jeppe.dyrby@gmail.com","onPremisesSamAccountName":"jeppe","userType":"Member"},"time":"2023-09-01T08:05:33.408488723Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/service/v0/users.go:309","message":"calling create user on backend"} {"level":"debug","service":"graph","request-id":"graph-5fcfb8df68-vt4nm/hpn7uCmHvY-035359","backend":"ldap","time":"2023-09-01T08:05:33.408505955Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:178","message":"CreateUser"} {"level":"debug","service":"graph","time":"2023-09-01T08:05:33.408529798Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"debug","service":"graph","backend":"ldap","base":"uid=jeppe,ou=users,dc=owncloud,dc=com","filter":"(objectClass=inetOrgPerson)","scope":0,"sizelimit":1,"attributes":["displayname","uid","mail","uid","sn","givenname","ownCloudUserEnabled","ownCloudUserType"],"time":"2023-09-01T08:05:33.415204592Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap.go:426","message":"getEntryByDN"} {"level":"debug","service":"graph","time":"2023-09-01T08:05:33.415227511Z","line":"github.com/owncloud/ocis/v2/services/graph/pkg/identity/ldap/reconnect.go:201","message":"using existing Connection"} {"level":"debug","service":"graph","request-id":"","proto":"HTTP/1.1","method":"POST","status":200,"path":"/graph/v1.0/users","duration":244.903951,"bytes":147,"time":"2023-09-01T08:05:33.600080289Z","line":"github.com/owncloud/ocis/v2/ocis-pkg/middleware/logger.go:27"} ```

the user shows up in the ldap server

owncloud / ocis