Anmeldung an SAC konnte nicht durchgeführt werden

UCS - Univention Corporate Server
,
#1

Hallo,

bei dem Versuch sich an der Admin-Weboberfläche von Scalix (server/sac) anzumelden erscheint folgender Fehler:

Anmeldung konnte nicht durchgeführt werden
Konfigurationsdaten konnten nicht geladen werden.
Ein Problem mit dem Administrationsserver ist aufgetreten.

Den bereits existierenden Forenbeitrag habe ich ausprobiert - ohne Erfolg:
(ubermanager.notification.listener.address=*)

Versionen:
Scalix 11.4.6
Univention: 2.2.2-3

Bin für jede Hilfe dankbar.

Gruß
BS

#2

Hallo,
zum Zeitpunkt des Anmeldeversuchs sollte etwas in /var/opt/scalix/??/tomcat/logs/scalix-caa.log protokolliert werden.
Die catalina.out im gleichen Verzeichnis ist auch u.U. hilfreich.

Viele Grüße,
Dirk Ahrnke

#3

Hallo,

danke für den Tip. Leider finde ich keinen richtigen Hinweis auf eine Fehlerursache.
In der scalix-caa.log fällt mir nur diese Zeile auf:

2010-04-13 09:02:36,606 FATAL [RESServiceHandler.GetMailNodesList:1004] java.lang.NumberFormatException: For input string: "6 ":ucs1.bergland-gruppe.de java.lang.NumberFormatException: For input string: "6 "
In die catalina.out wird während der Anmeldung nichts geschrieben. Hier die letzten Einträge nach Neustart:

API:WARN - cannot locate log4j properties file at: /var/opt/scalix/u1/platform/log4j.properties Loading platform API configuration from file /var/opt/scalix/u1/platform/platform.properties SIS received contextInitialized event SIS initialized with config from /var/opt/scalix/u1/sis/sis.properties scalix.instance is '/var/opt/scalix/u1' SIS: sis-root-directory is /var/opt/scalix/u1/sis SIS: log4j-init-file is /var/opt/scalix/u1/sis/log4j.properties log4j:WARN No appenders could be found for logger (org.apache.catalina.core.ContainerBase.[Catalina].[ucs1.bergland-gruppe.de].[/wireless]). log4j:WARN Please initialize the log4j system properly. CONFIG - WARN - cannot locate log4j properties file at: /var/opt/scalix/u1/wireless/log4j.properties CONFIG - Loading Wireless configuration from file /var/opt/scalix/u1/wireless/wireless.properties 12.04.2010 22:07:59 org.apache.coyote.http11.Http11BaseProtocol start INFO: Starting Coyote HTTP/1.1 on http-8080 12.04.2010 22:07:59 org.apache.jk.common.ChannelSocket init INFO: JK: ajp13 listening on ucs1.bergland-gruppe.de/172.21.12.12:8009 12.04.2010 22:07:59 org.apache.jk.server.JkMain start INFO: Jk running ID=0 time=0/20 config=null 12.04.2010 22:07:59 org.apache.catalina.storeconfig.StoreLoader load INFO: Find registry server-registry.xml at classpath resource 12.04.2010 22:07:59 org.apache.catalina.startup.Catalina start INFO: Server startup in -28785976 ms

Ich werde daraus leider nicht schlau.
Danke für jede Hilfe.
Gruß
BS

#4

Der RES (aka Management Agent) liefert Daten, die die CAA nicht mag.
Wenn in scalix-res.log im gleichen Verzeichnis zunächst nichts verwertbares drinsteht, kann man das Logging auch gesprächiger machen und dem RES beim Arbeiten zusehen.
Dazu in /var/opt/scalix/??/res/config/log4j.properties Zeile 2 und 3 von INFO auf DEBUG stellen. Wenn Sie einen kompletten Neustart des scalix-tomcat vermeiden wollen, reicht auch ein

touch /var/opt/scalix/??/tomcat/webapps/res/WEB-INF/web.xml
#5

Im scalix-res.log sind folgende Fehlermeldungen zu finden.
Vermutlich gibt es hier Probleme mit den Paketnamen unter Univention.
Wo sind die Pakete unter Univention verhaftet ?

[quote]2010-04-19 17:12:38,825 DEBUG [CmdExecution.executeCmd:143] COMMAND: /usr/bin/dpkg -p scalix-ser
ver
2010-04-19 17:12:38,969 DEBUG [RESDispatcherServlet.dumpResponse:302] —> RES Sending Response
XML Document <-----
2010-04-19 17:12:38,970 DEBUG [RESDispatcherServlet.dumpResponse:309] <?xml version=“1.0” encodi
ng=“UTF-8”?>


FAILED:1



<Line value=“und dpkg --contents (= dpkg-deb --contents) zum Auflisten ihres Inhalts.”/

  </Output>
[/quote]

GG

#6

Guido,
das ist ein Bug, aber keiner, der mit dem ursprünglichen Problem zu tun hat. Weiter unten im RES-log sollte noch was kommen…

Zu Deinem Log:
Das Paket scalix-server heißt unter UCS “scalix-univention-server”. Zumindest für 11.4.x.
Diese Änderung (durch die Leute, die bei Scalix für die Paketierung zuständig sind) hatte sich wohl noch nicht bis zu den SAC-Entwicklern herungesprochen. Ab Scalix 11.5. wird das wieder “normal”, also scalix-server. Also wird sich das dann auch erledigt haben.

Es erzeugt aber keine weiteren Probleme, mal abgesehen davon, daß die Informationen zum scalix-server Paket im SAC nicht zu sehen sind.

Gruß,
Dirk

#7

im scalix-res.log sind ansonsten keine Fehler zu finden, aber im scalix-caa.log ist ein FATAL

[quote]2010-04-20 17:36:38,102 DEBUG [SOAPDispatcherServlet.onMessage:159] **** Start o
f Message Handling ****
2010-04-20 17:36:38,103 DEBUG [SOAPHelper.getElementValue:144] Found ServiceType
2010-04-20 17:36:38,103 DEBUG [CAAConfigLoader.getValue:56] Looking for config f
or scalix.res, key disabled found null
2010-04-20 17:36:38,104 DEBUG [SOAPHelperUtils.getSoapBodyElement:179] Body elem
ent1 CAARequestMessage = null
2010-04-20 17:36:38,104 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body elem
ent2 ServiceType = scalix.res
2010-04-20 17:36:38,104 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body elem
ent2 Credentials = null
2010-04-20 17:36:38,104 DEBUG [SOAPHelperUtils.getSoapBodyElement:190] Found Cre
dentials
2010-04-20 17:36:38,105 DEBUG [SOAPHelperUtils.getCredentials:255] local name=id
2010-04-20 17:36:38,105 DEBUG [SOAPHelperUtils.getCredentials:256] qualified nam
e=id
2010-04-20 17:36:38,105 DEBUG [SOAPHelperUtils.getCredentials:272] local name=na
me
2010-04-20 17:36:38,105 DEBUG [SOAPHelperUtils.getCredentials:273] qualified nam
e=name
2010-04-20 17:36:38,105 DEBUG [SOAPHelperUtils.getCredentials:277] value=Adminis
trator
2010-04-20 17:36:38,106 DEBUG [SOAPHelperUtils.getCredentials:272] local name=pa
sswd
2010-04-20 17:36:38,106 DEBUG [SOAPHelperUtils.getCredentials:273] qualified nam
e=passwd
2010-04-20 17:36:38,106 DEBUG [SOAPHelperUtils.getCredentials:282] value=xxxxxxx
xx
2010-04-20 17:36:38,106 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:69] Body
element1 CAARequestMessage = null
[/quote]
…

[quote]2010-04-20 17:36:38,113 DEBUG [RESService.authenticateAndAuthorizeUser:218] AUTH
previously authenticated as Administrator?
2010-04-20 17:36:38,113 DEBUG [RESService.authenticateAndAuthorizeUser:241] AUTH
yes, pre-authenticated…
2010-04-20 17:36:38,114 DEBUG [RESService.authenticateAndAuthorizeUser:274] AUTH
previously authorized?
2010-04-20 17:36:38,114 DEBUG [RESService.authenticateAndAuthorizeUser:295] AUTH
*[/quote]
…

[quote]2010-04-20 17:36:38,116 DEBUG [RESService.authenticateAndAuthorizeUser:384] AUTH
done
2010-04-20 17:36:38,117 DEBUG [CAAConfigLoader.getValue:56] Looking for config f
or scalix.res, key connection.mode found 1
2010-04-20 17:36:38,117 DEBUG [CAAConnectionManager.getConnection:71] Connection
mode is 1
2010-04-20 17:36:38,117 DEBUG [CAAConfigLoader.getValue:56] Looking for config f
or scalix.res, key connection.configurator.class found com.scalix.caa.framework.
CAAConnectionPoolManager
2010-04-20 17:36:38,118 DEBUG [CAAConnectionPoolManager.logConnectionPool:325] C
onnection pool scalix.res status: min=2,max=10,size=2,used=0
2010-04-20 17:36:38,118 DEBUG [CAAConnectionPoolManager.getFreeConnectionFromPoo
l:129] Looking at connection 0
2010-04-20 17:36:38,118 DEBUG [CAAConnectionPoolManager.getFreeConnectionFromPoo
l:146] Found a free connection (0) for scalix.res and endpoint ucs1.bergl
and-gruppe.de:80/res/RESDispatcher
2010-04-20 17:36:38,118 DEBUG [CAAConnectionPoolManager.getFreeConnectionFromPoo
l:199] Retrieved connection from pool for scalix.res and endpoint ucs1.be
rgland-gruppe.de:80/res/RESDispatcher

2010-04-20 17:36:38,119 DEBUG [CAAConnectionPoolManager.logConnectionPool:325] C
onnection pool scalix.res status: min=2,max=10,size=2,used=1
2010-04-20 17:36:38,120 FATAL [RESServiceHandler.GetMailNodesList:1004] java.lan
g.NumberFormatException: For input string: "6 ":ucs1.bergland-gruppe.de
java.lang.NumberFormatException: For input string: "6 "
at java.lang.NumberFormatException.forInputString(Unknown Source)
at java.lang.Integer.parseInt(Unknown Source)
at java.lang.Integer.parseInt(Unknown Source)
at com.scalix.sac.ubermgr.res.RESServiceHandler.GetMailNodesList(RESServ
iceHandler.java:970)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at com.scalix.sac.ubermgr.caa.RESService.doRequest(RESService.java:134)
at com.scalix.caa.soap.SOAPDispatcherServlet.onMessage(SOAPDispatcherSer
vlet.java:268)
at com.scalix.caa.soap.SAAJServlet.doPost(SAAJServlet.java:123)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appl
icationFilterChain.java:269)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationF
ilterChain.java:188)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperV
alve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextV
alve.java:172)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.j
ava:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.j
ava:117)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineVal
ve.java:108)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.jav
a:174)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:200)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:775)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.ja
va:704)
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSock
et.java:897)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
ool.java:689)
at java.lang.Thread.run(Unknown Source)
2010-04-20 17:36:38,120 DEBUG [CAAConnectionPoolManager.freeConnection:88] Freei
ng a connection
2010-04-20 17:36:38,120 DEBUG [CAAConnectionPoolManager.logConnectionPool:325] C
onnection pool scalix.res status: min=2,max=10,size=2,used=0
2010-04-20 17:36:38,121 ERROR [GetMailNodesList.buildResponseMessage:107] Skippi
ng server ucs1.bergland-gruppe.de. No document received!
2010-04-20 17:36:38,122 DEBUG [SAAJServlet.doPost:130] ************ Request End
Success ***************
[/quote]

#8

Ich glaube, da wird ein “sxshowmn” ausgeführt (sollte genau im RES-log zu sehen sein).
Was zeigt der, wenn man es manuell ausführt?

#9

Hallo Dirk,

da hatte ich im Scalix Forum auch schon was zu gefunden, aber bei uns sieht das extrem unverfänglich aus.

root@ucs1:~# omshowmn
** ucs1

Gruss
Guido

#10

Schau mal auf den FATAL im caa-log bei 2010-04-20 17:36:38,120.
Welcher Befehl wird da laut res-log ausgeführt?

Ausserdem wird IMHO durch den RES wirklich sxshowmn (ein Shellskript) und nicht omshowmn (ein binary) aufgerufen.

#11

Hallo Dirk,

sxshowmn liefert:

internet mime Null Null
internet,tnef tnef Null Null
ucs1 primary Null Null

wird aber nicht im res-log angezeigt.
Ich finde im betreffenden Zeiraum nur sxconfig Aufrufe.
Davor sind lediglich die Paketüberprüfungen die wir schon am Anfang als Problemursache ausgeschlossen hatten.
Nach dem sxconfig ist noch ein omshowpwd mit unverfänglichem Output und das war es.

[code]2010-04-20 17:36:36,809 DEBUG [RESDispatcherServlet.dumpRequest:294] <?xml version="1.0" encoding="UTF-8"?>







2010-04-20 17:36:36,810 DEBUG [CmdExecution.executeCmd:141] ENVIRONMENT: LANG=de_DE.UTF-8 OM_CHAR=UTF-8 OMCU
RRENT=ucs1 HOME=/tmp PWD=/tmp
2010-04-20 17:36:36,810 DEBUG [CmdExecution.executeCmd:143] COMMAND: /opt/scalix/bin/sxconfig --get -t gener
al.all
2010-04-20 17:36:36,934 DEBUG [RESDispatcherServlet.dumpResponse:302] —> RES Sending Response XML Document
<-----
2010-04-20 17:36:36,934 DEBUG [RESDispatcherServlet.dumpResponse:309] <?xml version="1.0" encoding="UTF-8"?>


OK:0













[/code]

[code]2010-04-20 17:36:37,642 DEBUG [RESDispatcherServlet.dumpRequest:294] <?xml version="1.0" encoding="UTF-8"?>







2010-04-20 17:36:37,643 DEBUG [CmdExecution.executeCmd:141] ENVIRONMENT: LANG=de_DE.UTF-8 OM_CHAR=UTF-8 OMCU
RRENT=ucs1 HOME=/tmp PWD=/tmp
2010-04-20 17:36:37,643 DEBUG [CmdExecution.executeCmd:143] COMMAND: /opt/scalix/bin/sxconfig --get -t ornia
sys.all
2010-04-20 17:36:37,766 DEBUG [RESDispatcherServlet.dumpResponse:302] —> RES Sending Response XML Document
<-----
2010-04-20 17:36:37,766 DEBUG [RESDispatcherServlet.dumpResponse:309] <?xml version="1.0" encoding="UTF-8"?>


OK:0











[/code]

Gruss
Guido

#12

Nach dem omshowpwd kommt der sxshowmn.
Zum Vergleich (leicht gekürzt):

[code]2010-04-23 10:45:55,765 DEBUG [CmdExecution.executeCmd:141] ENVIRONMENT: LANG=en_US.UTF-8 OM_CHAR=UTF-8 OMCURRENT=mc80 HOME=/tmp PWD=/tmp
2010-04-23 10:45:55,765 DEBUG [CmdExecution.executeCmd:143] COMMAND: /opt/scalix/bin/sxconfig --get -t orniasys.all
2010-04-23 10:45:55,903 DEBUG [RESDispatcherServlet.dumpResponse:302] —> RES Sending Response XML Document <-----
2010-04-23 10:45:55,903 DEBUG [RESDispatcherServlet.dumpResponse:309] <?xml version="1.0" encoding="UTF-8"?>


OK:0

…


2010-04-23 10:45:56,090 DEBUG [RESDispatcherServlet.dumpRequest:260] —> RES Incoming Request Headers <----
2010-04-23 10:45:56,090 DEBUG [RESDispatcherServlet.dumpRequest:265] content-type:text/xml; charset=utf-8
2010-04-23 10:45:56,091 DEBUG [RESDispatcherServlet.dumpRequest:265] user-agent:Scalix CAA/Ubermanager 1.0
2010-04-23 10:45:56,091 DEBUG [RESDispatcherServlet.dumpRequest:265] host:mc80.it25.de
2010-04-23 10:45:56,091 DEBUG [RESDispatcherServlet.dumpRequest:265] accept:text/html, image/gif, image/jpeg, *; q=.2, /; q=.2
2010-04-23 10:45:56,091 DEBUG [RESDispatcherServlet.dumpRequest:265] connection:keep-alive
2010-04-23 10:45:56,092 DEBUG [RESDispatcherServlet.dumpRequest:265] content-length:171
2010-04-23 10:45:56,092 DEBUG [RESDispatcherServlet.dumpRequest:265] Max-Forwards:10
2010-04-23 10:45:56,092 DEBUG [RESDispatcherServlet.dumpRequest:268] —> RES Incoming Request XML Document (Not a secure request, OK) <-----
2010-04-23 10:45:56,092 DEBUG [RESDispatcherServlet.dumpRequest:294] <?xml version="1.0" encoding="UTF-8"?>






2010-04-23 10:45:56,093 DEBUG [CmdExecution.executeCmd:141] ENVIRONMENT: LANG=en_US.UTF-8 OM_CHAR=UTF-8 OMCURRENT=mc80 HOME=/tmp PWD=/tmp
2010-04-23 10:45:56,093 DEBUG [CmdExecution.executeCmd:143] COMMAND: /opt/scalix/bin/omshowpwd -j
2010-04-23 10:45:56,220 DEBUG [RESDispatcherServlet.dumpResponse:302] —> RES Sending Response XML Document <-----
2010-04-23 10:45:56,220 DEBUG [RESDispatcherServlet.dumpResponse:309] <?xml version="1.0" encoding="UTF-8"?>


OK:0

…



2010-04-23 10:45:56,276 DEBUG [RESDispatcherServlet.dumpRequest:260] —> RES Incoming Request Headers <----
2010-04-23 10:45:56,276 DEBUG [RESDispatcherServlet.dumpRequest:265] content-type:text/xml; charset=utf-8
2010-04-23 10:45:56,277 DEBUG [RESDispatcherServlet.dumpRequest:265] user-agent:Scalix CAA/Ubermanager 1.0
2010-04-23 10:45:56,277 DEBUG [RESDispatcherServlet.dumpRequest:265] host:mc80.it25.de
2010-04-23 10:45:56,277 DEBUG [RESDispatcherServlet.dumpRequest:265] accept:text/html, image/gif, image/jpeg, *; q=.2, /; q=.2
2010-04-23 10:45:56,277 DEBUG [RESDispatcherServlet.dumpRequest:265] connection:keep-alive
2010-04-23 10:45:56,278 DEBUG [RESDispatcherServlet.dumpRequest:265] content-length:140
2010-04-23 10:45:56,278 DEBUG [RESDispatcherServlet.dumpRequest:265] Max-Forwards:10
2010-04-23 10:45:56,278 DEBUG [RESDispatcherServlet.dumpRequest:268] —> RES Incoming Request XML Document (Not a secure request, OK) <-----
2010-04-23 10:45:56,279 DEBUG [RESDispatcherServlet.dumpRequest:294] <?xml version="1.0" encoding="UTF-8"?>




2010-04-23 10:45:56,279 DEBUG [CmdExecution.executeCmd:141] ENVIRONMENT: LANG=en_US.UTF-8 OM_CHAR=UTF-8 OMCURRENT=mc80 HOME=/tmp PWD=/tmp
2010-04-23 10:45:56,279 DEBUG [CmdExecution.executeCmd:143] COMMAND: /opt/scalix/bin/sxshowmn
2010-04-23 10:45:56,466 DEBUG [RESDispatcherServlet.dumpResponse:302] —> RES Sending Response XML Document <-----
2010-04-23 10:45:56,466 DEBUG [RESDispatcherServlet.dumpResponse:309] <?xml version="1.0" encoding="UTF-8"?>


OK:0






[/code]

#13

nö,
da kommt nichts mehr. Nach dem omshowpwd -j kommen nur noch die Heartbeat´s.

Guido

#14

Kommt das ‘"6 ":ucs1…’ ggf. aus der ubermanager.properties oder res.properties?

#15

Hallo Dirk,
bei Configfiles sehen normal aus, da hatte ich auch schon geschaut, alle stellen an denen ucs1 auftaucht sind ok.

Ich habe aber mal die letzten Backup´s unter /var/univention-backup verglichen

hier wurde res.env.lang=de_DE.UTF-8 gegen en_US.UTF-8 getauscht.
Könnte hier ein Problem existieren ?

Können wir die Konfiguration mit univention-scalix-conffile nicht einfach nochmal durchführen ?

Guido

#16

Hallo,

das Problem konnte durch neuerzeugen der Scalixkonfiguration mit den Befehl /usr/share/univention-scalix/univention-scalix-conffile behoben werden.

Mit freundlichen Grüssen
Tobias Scherer

#17

Schön, daß der Fehler behoben ist, aber in Anbetracht des Ping-Pings zwischen Guido und mir würde mich dann doch interessieren, was, bzw. welche Konfigurationsdatei die Ursache war.
Besteht die Chance dazu?

#18

Das müsste eigentlich möglich sein. Das Tool univention-scalix-conffile speichert die alten und die neuen Konfigurationsdateien unterhalb dem Verzeichnis /var/univention-backup/scalix/.

Mastodon