OCIS 2 beta: login error with "admin"

I upgraded an older dockerized ocis installation to the ocis 2 beta binary setup (daily from 22.8), following docs at Oops! You're lost and Oops! You're lost

While OCIS runs, the login with the admin PW created upon “ocis init” fails and I see a http 500 error. The logs show strange errors about some missing ldap backend:

Aug 22 18:55:22 cloud3 ocis[1538]: {"level":"error","service":"idm","bind_dn":"uid=idp,ou=sysusers,o=libregraph-idm","op":"bind",
"remote_addr":"127.0.0.1:50260","time":"2022-08-22T18:55:22.902607904+02:00","message":"invalid credentials"}
Aug 22 18:55:22 cloud3 ocis[1538]: {"level":"error","service":"idp","error":"ldap identifier backend logon connect error: LDAP Re
sult Code 49 \"Invalid Credentials\": ","time":"2022-08-22T18:55:22.903578178+02:00","message":"identifier failed to logon with b
ackend"}

Note: OCIS runs on a server with haproxy for ssl termination, ocis.env:

OCIS_INSECURE=false
OCIS_URL=https://ocis.netzwissen.de
#OCIS_URL=https://localhost:9200
# haproxy handles ssl
PROXY_TLS=false
PROXY_HTTP_ADDR=0.0.0.0:9200
OCIS_BASE_DATA_PATH=/var/www/ocisdata
OCIS_LOG_LEVEL=error

Any ideas??

The log says the system user idp (a service account for the identity provider service) has provided the wrong password when trying to talk to the idm (the identity managment).

Running ocis init has created (or should have created) a new random password for that user (IDM_IDPSVC_PASSWORD or idp_password in the config file) and written it into the internal boltdb as well as the config file. Could you double check the /path/to/ocis.yaml contains an idp_password entry?

If so try running LDAPTLS_REQCERT=never ldapsearch -x -H ldaps://127.0.0.1:9235 -x -D uid=idp,ou=sysusers,o=libregraph-idm -W -b o=libregraph-idm objectclass=inetorgperson. It should dump all your users. Maybe change the ldaps URL.

You can try to reset the idp users password using LDAPTLS_REQCERT=never ldappasswd -x -H ldaps://127.0.0.1:9235 -D "uid=libregraph,ou=sysusers,o=libregraph-idm" -W -S "uid=idp,ou=sysusers,o=libregraph-idm". You will have to provide the libregraph users password, which you should be able to find /path/to/ocis.yaml.

What version of ocis exactly did you deploy previously? Depending on the version the idm password was either hardcoded or stored in the no longer existing accounts service.

Hi,
ocis.yaml >> the idp_password exists

If so try running LDAPTLS_REQCERT=never ldapsearch

I never used LDAP before on that machine. Thats the reason why i dont understand the ldap error in the log :wink:

What version of ocis exactly did you deploy previously? Depending on the version the idm password was either hardcoded or stored in the no longer existing accounts service.

Puh, I don’t remember, but it was from 2021.
But we can really start from the scratch and delete stuff, there is no valuable data on that server.

I want to setup the current OCIS beta and probably connect it to an already running IDP (keycloak 18), which is used in production for OIDC with OC 10x.

Puh, I don’t remember, but it was from 2021.

Ok. There have been a couple for backwards incompatbile changes not only with regards to the user management but also for the decomposedfs storage layout before we went into beta (note: During beta we try very hard to not introduce these kind of changes anymore).

But we can really start from the scratch and delete stuff, there is no valuable data on that server.

Yeah, I think in that case it would be really better to start from scratch. (by deleteing the ocis.yaml and everything in your OCIS_BASE_DATA_PATH).

I want to setup the current OCIS beta and probably connect it to an already running IDP (keycloak 18), which is used in production for OIDC with OC 10x.

Regarding the integration with an external IDP it might be a good idea to look into our deployment examples for ocis (specifically ocis/deployments/examples/ocis_keycloak at master · owncloud/ocis · GitHub). Even if you’re not planning to use docker-compose. They should give you some idea about the settings ocis needs for running with an external idp.

1 Like

OK, I cleaned up all the old stuff (ocis,yaml, data structures in datapath) and started again with beta 7 and ocis init with IDM_CREATE_DEMO_USERS=true.

The ocis process runs but the login still fails, because ocis tries to reach an ldap server which is not available:

Sep 04 10:41:12 cloud3 systemd[1]: Started OCIS server.
Sep 04 10:41:14 cloud3 ocis[48376]: {"level":"error","service":"graph","error":"LDAP Result Code 200 \"Network Error\": dial tcp 127.0.
0.1:9235: connect: connection refused","time":"2022-09-04T10:41:14.071066858+02:00","message":"could not get ldap Connection"}
Sep 04 10:41:14 cloud3 ocis[48376]: {"level":"error","service":"graph","error":"LDAP Result Code 200 \"Network Error\": dial tcp 127.0.
0.1:9235: connect: connection refused","time":"2022-09-04T10:41:14.07222107+02:00","message":"autoconnect could not get ldap Connection
"}

There is no openldap on the test system :wink:

Bye, Thommie

There is no openldap on the test system

ocis itself ships with a small builtin LDAP server (based on https://github.com/libregraph/idm) so even you don’t have an OpenLDAP server installed, there is an LDAP service running inside ocis.

Are these 3 lines you paste the only thing you get in the logs or is there more? How exactly did you start ocis? What exact error do you get? And which user are you trying to log in as?

The start sequence from the systemd service file

[Service]
Type=simple
User=ocis
Group=ocis
EnvironmentFile=/etc/ocis/ocis.env
ExecStart=ocis server
Restart=always

Contents of the env file:

OCIS_INSECURE=false
OCIS_URL=https://ocis.netzwissen.de
#OCIS_URL=https://localhost:9200
# haproxy handles ssl
PROXY_TLS=false
PROXY_HTTP_ADDR=0.0.0.0:9200
OCIS_BASE_DATA_PATH=/var/www/ocisdata
OCIS_LOG_LEVEL=error
IDM_CREATE_DEMO_USERS=true

journalctl -u after start

Sep 05 09:42:27 cloud3 systemd[1]: Started OCIS server.
Sep 05 09:42:29 cloud3 ocis[53904]: {"level":"error","service":"graph","error":"LDAP Result Code 200 \"Network Error\": di>
Sep 05 09:42:29 cloud3 ocis[53904]: {"level":"error","service":"graph","error":"LDAP Result Code 200 \"Network Error\": di>

Any login attempt is answered with a http 500 error after the

POST https://ocis.netzwissen.de/signin/v1/identifier/_/logon

This error is a bit misleading it happens because some ocis service try to contact the builtin LDAP interface before ocis is fully up (I just opened https://github.com/owncloud/ocis/issues/4520 for this). It would point to a problem if you constantly get the error while running ocis.

I think to better understand what is going wrong in your case we need to increase log-levels. Please try running with ocis OCIS_LOG_LEVEL set to debug.

ok, login with “admin” “admin” and loglevel debug:

Sep 06 10:31:36 cloud3 ocis[57008]: {"level":"debug","service":"proxy","policy":"ocis","method":"POST","prefix":"/signin/","path":"/signin/v1/identifier/_/logon","routeType":"prefix","time":"2022-09-06T10:31:36.111271684+02:00","message":"director found"}
Sep 06 10:31:36 cloud3 ocis[57008]: {"level":"debug","service":"idm","addr":"{\"IP\":\"127.0.0.1\",\"Port\":9235,\"Zone\":\"\"}","time":"2022-09-06T10:31:36.11448221+02:00","message":"New Connection"}
Sep 06 10:31:36 cloud3 ocis[57008]: {"level":"error","service":"idm","bind_dn":"uid=idp,ou=sysusers,o=libregraph-idm","op":"bind","remote_addr":"127.0.0.1:47040","time":"2022-09-06T10:31:36.259422088+02:00","message":"invalid credentials"}
Sep 06 10:31:36 cloud3 ocis[57008]: {"level":"error","service":"idp","error":"ldap identifier backend logon connect error: LDAP Result Code 49 \"Invalid Credentials\": ","time":"2022-09-06T10:31:36.260163579+02:00","message":"identifier failed to logon with backend"}
Sep 06 10:31:36 cloud3 ocis[57008]: {"level":"debug","service":"idp","request":"","proto":"HTTP/1.1","method":"POST","status":500,"path":"/signin/v1/identifier/_/logon","duration":147.302258,"bytes":44,"time":"2022-09-06T10:31:36.260450524+02:00"}
Sep 06 10:31:36 cloud3 ocis[57008]: {"level":"info","service":"proxy","proto":"HTTP/1.1","request":"cloud3/LPHueaR0Js-000099","remote-addr":"79.249.24.151","method":"POST","status":500,"path":"/signin/v1/identifier/_/logon","duration":150.088117,"bytes":44,"time":"2022-09-06T10:31:36.260930182+02:00","message":"access-log"}

We can also switch over to talk.owncloud.com if you wish, I am online now …

Hm, for some reason the password for the “idp” service user configured in the ocis configuration file still doesn’t match the one in the user database. Did you, by chance, change any of the passwords defined in ocis.yaml after starting ocis for the first time? You can try to reinitialize the user database (since you don’t have any real data yet):

  • stop ocis
  • move away/delete the users db. Should be /var/www/ocisdata/idm/ocis.boltdb in your case
  • start ocis again, that should reinitialize the db with the demo users and the service passwords defined in your ocis.yaml

Feel free open a discussion in the infinitescale channel

OK, I still had some old stuff in /ocisdata, sorry ;-(.

I deleted everything again. As user “ocis” (the home dir is /var/www/ocis) I created a new .yaml with “ocis init” and saved the displayed password of the admin user. Then I started the process through systemctl which created the structures and files below /var/www/ocisdata/, according to the settings in the /etc/ocis/ocis.env file

The login with the admin pw is still not possible, but the error code in the UI changed from http 500 to http 400 and the ldap errors in the log are gone. As far as I understand it, we can start a search for the user credentials in the boltdb, but the results are still not successful. The root cause looks like some invalid OIDC redirect:

Sep 06 16:43:17 cloud3 ocis[58183]: {"level":"debug","service":"idp","error":"invalid redirect_uri: https://cloud3.netzwissen.de/oidc-callback.html","time":"2022-09-06T16:43:17.560755265+02:00","message":"rejecting identifier logon request"}

See logfile, I*ve put it in a public directory on my OC server .

ocis debug log

Correct. I think this might be caused by a wrong OCIS_URL setting (or a configuration issue with the proxy you’re running in front of ocis). What is the public hostname you’re using to access the ocis instance? In the env file you set https://ocis.netzwissen.de but the logs seem to suggest https://cloud3.netzwissen.de

… haha, “four eyes principle” is always good :wink:
cloud3.netzwissen.de is the DNS A record for the host machine (a cloud instance at hetzner). ocis.netzwissen.de is just a CNAME. haproxy redirects to the correct backend (127.0.0.1:9200) based on the host header in the request. Docs:

I see no more errors in the debug log, but if I change from

OCIS_URL=https://ocis.netzwissen.de

to

OCIS_URL=https://cloud3.netzwissen.de

the login still fails, now because the API redirect goes to

POST

https://cloud3.netzwissen.de/signin/v1/identifier/_/logon

instead of

POST

https://ocis.netzwissen.de/signin/v1/identifier/_/logon

Is there another env variable to define the global API endpoint or some kind of “hostname prefix” for the API calls? I went through Services :: ownCloud Documentation but I am not shure which variable is correct …

Actually I think https://ocis.netzwissen.de is the correct OCIS_URL setting in your case. It should be the URL that it used for externally accessing ocis. I was just wondering about that
invalid redirect_uri message from ocis and tried to understand your setup.

I must admit I can’t really tell from where the WebUI is picking up that wrong redirect_uri when you had still set OCIS_URL=https://ocis.netzwissen.de. Could you try getting back to OCIS_URL=https://ocis.netzwissen.de and try to access the site from an incognito tab, just to rule out some weird caching issues.

Also you really might wanna try to reachout to the infinitescale channel on talk.owncloud.com for getting some more eyes on this.