65univention-ox.inst schlägt fehl

ralf2201 · April 28, 2018, 8:15pm

Nach einem Update versuche ich meinen Slave mit OpenXchange wieder mit dem Master zu joinen. Abbruch immer bei script 65univention-ox. Kann mir jemand helfen, in welchen logs ich hier zu suchen haben.

Schwardt · April 29, 2018, 5:31am

Hallo,

die Logausgaben der Joinskripte werden in /var/log/univention/join.log gesammelt.

Viele Grüße,

Sönke

ralf2201 · April 29, 2018, 10:53am

Hallo,

danke für die schnelle Antwort. Ich vermute das Problem bei OpenXchange. Ich versuche mal die Log Datei anzuhängen.

Dann habe ich noch einen Ausschnitt der Logdatei /var/log/open-xchange/open-xchange.log.0 angehängt. Hier scheint es einen Fehler zu geben.

log.txt (177.4 KB)

2018-04-29T12:30:02,936+0200 INFO  [RMI TCP Connection(2026)-186.177.235.210] com.openexchange.admin.storage.mysqlStorage.OXContextMySQLStorage.change(OXContextMySQLStorage.java:2542)
Context 10 changed.
2018-04-29T12:30:05,084+0200 ERROR [RMI TCP Connection(2034)-186.177.235.210] com.openexchange.admin.rmi.impl.BasicAuthenticator.doAuthentication(BasicAuthenticator.java:261)
Admin authentication for user oxadmin
com.openexchange.admin.rmi.exceptions.InvalidCredentialsException: Authentication failed
	at com.openexchange.admin.rmi.impl.BasicAuthenticator.doAuthentication(BasicAuthenticator.java:259)
	at com.openexchange.admin.rmi.impl.OXGroup.list(OXGroup.java:798)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
	at sun.rmi.transport.Transport$2.run(Transport.java:203)
	at sun.rmi.transport.Transport$2.run(Transport.java:200)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:199)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:829)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.access$400(TCPTransport.java:620)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:685)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:682)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
	at java.lang.Thread.run(Thread.java:748)
2018-04-29T12:30:05,692+0200 INFO  [RMI TCP Connection(2037)-186.177.235.210] com.openexchange.admin.storage.mysqlStorage.OXContextMySQLStorage.change(OXContextMySQLStorage.java:2542)
Context 10 changed.
2018-04-29T12:30:07,441+0200 ERROR [RMI TCP Connection(2045)-186.177.235.210] com.openexchange.admin.rmi.impl.BasicAuthenticator.doAuthentication(BasicAuthenticator.java:261)
Admin authentication for user oxadmin
com.openexchange.admin.rmi.exceptions.InvalidCredentialsException: Authentication failed
	at com.openexchange.admin.rmi.impl.BasicAuthenticator.doAuthentication(BasicAuthenticator.java:259)
	at com.openexchange.admin.rmi.impl.OXGroup.list(OXGroup.java:798)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
	at sun.rmi.transport.Transport$2.run(Transport.java:203)
	at sun.rmi.transport.Transport$2.run(Transport.java:200)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:199)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:829)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.access$400(TCPTransport.java:620)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:685)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:682)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
	at java.lang.Thread.run(Thread.java:748)
2018-04-29T12:30:08,043+0200 INFO  [RMI TCP Connection(2048)-186.177.235.210] com.openexchange.admin.storage.mysqlStorage.OXContextMySQLStorage.change(OXContextMySQLStorage.java:2542)
Context 10 changed.
2018-04-29T12:30:09,749+0200 ERROR [RMI TCP Connection(2056)-186.177.235.210] com.openexchange.admin.rmi.impl.BasicAuthenticator.doAuthentication(BasicAuthenticator.java:261)
Admin authentication for user oxadmin
com.openexchange.admin.rmi.exceptions.InvalidCredentialsException: Authentication failed
	at com.openexchange.admin.rmi.impl.BasicAuthenticator.doAuthentication(BasicAuthenticator.java:259)
	at com.openexchange.admin.rmi.impl.OXGroup.list(OXGroup.java:798)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
	at sun.rmi.transport.Transport$2.run(Transport.java:203)
	at sun.rmi.transport.Transport$2.run(Transport.java:200)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:199)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:829)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.access$400(TCPTransport.java:620)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:685)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$1.run(TCPTransport.java:682)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
	at java.lang.Thread.run(Thread.java:748)

Schwardt · May 2, 2018, 11:32am

Hallo,

es sieht so aus, als ob entweder das Passwort des “oxadmin” oder des “oxadminmaster” nicht mehr mit dem in der Datei (oxadmin → /etc/ox-secrets/context10.secret bzw. oxadminmaster → /etc/ox-secrets/master.secret) übereinstimmt.

Bitte rufe als Benutzer root einmal die folgenden Befehle auf, um herauszufinden, welcher der beiden Accounts gestört ist:

ADMIN_PASSWORD=$(cat /etc/ox-secrets/master.secret) /opt/open-xchange/sbin/listcontext -A oxadminmaster

und

ADMIN_PASSWORD=$(cat /etc/ox-secrets/context10.secret) /opt/open-xchange/sbin/listuser -A oxadmin -c 10 -s oxadmin

Viele Grüße

Sönke

ralf2201 · May 2, 2018, 6:16pm

Hallo,

danke für die tolle Hilfe. Es war der oxadmin Account. Ich habe die Datei context10.secret entsprechend geändert und die Joinscripte laufen jetzt anstandslos durch.
Jetzt habe ich aber das Problem, dass sich meine user nicht an der OX App Suite anmelden können.

Der Benutzername oder das Passwort ist nicht korrekt. (LGI-0006)

Gruß

Ralf

Schwardt · May 3, 2018, 10:55am

Hallo Ralf,

über den Benutzer oxadmin werden vom UCS-System die Benutzer in der OX AppSuite gepflegt. Wenn da jetzt seit einiger Zeit das Passwort nicht gestimmt hat, kann es sein, dass Benutzerstamm im UCS-Verzeichnisdienst und in OX nicht mehr synchron sind.
In der Logdatei /var/log/open-xchange/open-xchange.log.0 sollte der Fehler (LGI-0006) auch auftauchen und genauere Hinweise geben, ob es den User wirklich nicht mehr in OX gibt oder ob ein anderes Problem vorliegt.
Zusätzlich kann man mit folgendem Befehl die OX-Benutzer auflisten lassen:

ADMIN_PASSWORD=$(cat /etc/ox-secrets/context10.secret) /opt/open-xchange/sbin/listuser -A oxadmin -c 10

Viele Grüße

Sönke

ralf2201 · May 3, 2018, 7:36pm

Hallo Sönke,

die Benutzer kann ich auflisten. Sind alle vorhanden. Wenn ich mich an der Suite anmelden will kommt im Logfile diese Meldung.

Jetzt habe ich mit Schrecken festgestellt, dass mein DC Version 4.3.0 hat und mein Slave, auf dem
OpenXchange läuft, hat Vdersion 4.2.3. Kann das Problem daher kommen?

2018-05-03T21:36:01,263+0200 INFO  [OXTimer-0000156] com.openexchange.usm.session.tasks.USMSessionCleanupTask.run(USMSessionCleanupTask.java:110)
Checked for old USM sessions, 0 were removed
 com.openexchange.database.schema=localhost_5
2018-05-03T21:36:02,984+0200 INFO  [OXWorker-0000156] com.openexchange.authentication.ucs.impl.UCSAuthentication.handleLoginInfo(UCSAuthentication.java:317)
Authentication against ldap server failed
 com.openexchange.grizzly.method=POST
 com.openexchange.grizzly.queryString=<none>
 com.openexchange.grizzly.remoteAddress=95.208.62.158
 com.openexchange.grizzly.remotePort=46074
 com.openexchange.grizzly.requestURI=/ajax/login
 com.openexchange.grizzly.serverName=srv05slv.intern.meinedomain.xyz
 com.openexchange.grizzly.servletPath=/ajax/login
 com.openexchange.grizzly.threadName=OXWorker-0000156
 com.openexchange.grizzly.userAgent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.139 Safari/537.36
 com.openexchange.login.authId=fe56b5b4ce8c483397e3121f670186b6
 com.openexchange.login.client=open-xchange-appsuite
 com.openexchange.login.clientIp=95.208.62.158
 com.openexchange.login.login=ralf
 com.openexchange.login.userAgent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.139 Safari/537.36
 com.openexchange.login.version=7.8.4-28
 com.openexchange.request.trackingId=402282782-201141403
javax.naming.AuthenticationException: [LDAP: error code 49 - Invalid Credentials]
	at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3154)
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3100)
	at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2886)
	at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2800)
	at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:319)
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:192)
	at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:210)
	at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:153)
	at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:83)
	at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684)
	at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:311)
	at javax.naming.InitialContext.init(InitialContext.java:244)
	at javax.naming.InitialContext.<init>(InitialContext.java:216)
	at javax.naming.directory.InitialDirContext.<init>(InitialDirContext.java:101)
	at com.openexchange.authentication.ucs.impl.UCSAuthentication.handleLoginInfo(UCSAuthentication.java:162)
	at com.openexchange.authentication.service.Authentication.login(Authentication.java:111)
	at com.openexchange.authentication.service.Authentication.login(Authentication.java:98)
	at com.openexchange.login.internal.NormalLoginMethod.doAuthentication(NormalLoginMethod.java:83)
	at com.openexchange.login.internal.LoginPerformer.doLogin(LoginPerformer.java:213)
	at com.openexchange.login.internal.LoginPerformer.doLogin(LoginPerformer.java:155)
	at com.openexchange.login.internal.LoginPerformer.doLogin(LoginPerformer.java:143)
	at com.openexchange.ajax.login.Login$1.doLogin(Login.java:109)
	at com.openexchange.ajax.login.AbstractLoginRequestHandler.loginOperation(AbstractLoginRequestHandler.java:224)
	at com.openexchange.ajax.login.AbstractLoginRequestHandler.loginOperation(AbstractLoginRequestHandler.java:182)
	at com.openexchange.ajax.login.Login.doLogin(Login.java:97)
	at com.openexchange.ajax.login.Login.handleRequest(Login.java:90)
	at com.openexchange.ajax.LoginServlet.doJSONAuth(LoginServlet.java:792)
	at com.openexchange.ajax.LoginServlet.doGet(LoginServlet.java:757)
	at com.openexchange.ajax.LoginServlet.doPost(LoginServlet.java:877)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at com.openexchange.ajax.AJAXServlet.doService(AJAXServlet.java:551)
	at com.openexchange.ajax.LoginServlet.service(LoginServlet.java:737)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:147)
	at com.openexchange.http.grizzly.servletfilter.RequestReportingFilter.doFilter(RequestReportingFilter.java:138)
	at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:137)
	at com.openexchange.http.grizzly.servletfilter.WrappingFilter.doFilter(WrappingFilter.java:204)
	at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:137)
	at com.openexchange.http.grizzly.service.http.OSGiAuthFilter.doFilter(OSGiAuthFilter.java:140)
	at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:137)
	at org.glassfish.grizzly.servlet.FilterChainImpl.invokeFilterChain(FilterChainImpl.java:106)
	at org.glassfish.grizzly.servlet.ServletHandler.doServletService(ServletHandler.java:224)
	at org.glassfish.grizzly.servlet.ServletHandler.service(ServletHandler.java:178)
	at com.openexchange.http.grizzly.service.http.OSGiMainHandler.service(OSGiMainHandler.java:223)
	at org.glassfish.grizzly.http.server.HttpHandler$1.run(HttpHandler.java:224)
	at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$MDCProvidingRunnable.run(CustomThreadPoolExecutor.java:2575)
	at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$Worker.runTask(CustomThreadPoolExecutor.java:841)
	at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$Worker.run(CustomThreadPoolExecutor.java:868)
	at java.lang.Thread.run(Thread.java:748)
2018-05-03T21:36:02,985+0200 INFO  [OXWorker-0000156] com.openexchange.login.internal.LoginPerformer.logLoginRequest(LoginPerformer.java:673)
Login:ralf IP:95.208.62.158 AuthID:fe56b5b4ce8c483397e3121f670186b6 Agent:Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.139 Safari/537.36 Client:open-xchange-appsuite(7.8.4-28) Interface:HTTP_JSON No session created.
 com.openexchange.grizzly.method=POST
 com.openexchange.grizzly.queryString=<none>
 com.openexchange.grizzly.remoteAddress=95.208.62.158
 com.openexchange.grizzly.remotePort=46074
 com.openexchange.grizzly.requestURI=/ajax/login
 com.openexchange.grizzly.serverName=srv05slv.intern.meinedomain.xyz
 com.openexchange.grizzly.servletPath=/ajax/login
 com.openexchange.grizzly.threadName=OXWorker-0000156
 com.openexchange.grizzly.userAgent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.139 Safari/537.36
 com.openexchange.request.trackingId=402282782-201141403

Grüße

Ralf

Schwardt · May 4, 2018, 3:57pm

Hallo,

das Maschinenkonto des Slaves ist hier anscheinend nicht in der Lage, eine Verbindung zum LDAP-Server aufzubauen (Authentication against ldap server failed), weshalb die Authentifizierung der Benutzer an der OX-Anmeldemaske dann auch fehlschlägt.
Die relevanten Einstellungen werden über UCR-Variablen gesetzt und sollten folgende Wert aufweisen:

ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.baseDn: @%@ldap/base@%@
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.bindDn: @%@ldap/hostdn@%@
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.bindPassword: @&@/etc/machine.secret@&@
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.contextIdAttribute: oxContextIDNum
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.ldapUrl: ldaps://@%@ldap/server/name@%@:7636
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.loginAttribute: uid
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.mailAttribute: mailPrimaryAddress
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.passwordChangeURL: https://@%@hostname@%@.@%@domainname@%@/univention/portal/
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.searchFilter: (&(objectClass=oxUserObject)(uid=%s))
ox/cfg/authplugin.properties/com.openexchange.authentication.ucs.useLdapPool: false

Bitte überprüfe einmal diese Werte und führe danach zur Sicherheit einmal die folgenden 2 Befehle aus:

/usr/sbin/commit-ox-ucr-variables
univention-check-join-status

Ersteres schreibt nochmal alle Einstellungen aus den UCR-Variablen in die entsprechenden OX-Konfigurationsdateien.
Letzteres prüft, ob das Maschinenkonto noch gültig ist und sollte Joined successfully zurückgeben.

Viele Grüße

Sönke

ralf2201 · May 4, 2018, 9:17pm

Hallo Sönke,

vielen Dank für die Hilfe.
Die UCR Variablen waren so vorhanden, nachdem ich die beiden Befehle
ausgeführt hatte, war alles wieder ok.

Gruß

Ralf

Schwardt · May 7, 2018, 8:50am

Hallo Ralf,

es wird dann das /usr/sbin/commit-ox-ucr-variables gewesen sein. univention-check-join-status ist ein read-only-Prüftool.

Viele Grüße

Sönke