verify_server_cert in opsi 4.0.7 -> kein connect mehr bei allen Clients

[tobi]

Hi,

nach dem update auf opsi 4.0.7 kann kein Windows Client mehr connecten.
verify_server_cert ist bei allen auf True gesetzt. (verify_server_cert_by_ca ist False)
Im Client Log erscheint:
Opsi service verification error: Service verification failed: HTTP header 'X-opsi-service-verification-key' missing (OpsiService.pyo|339)

Wenn ich händisch auf den Clients den Wert verify_server_cert auf False setze, funktioniert der connect wieder.
Gibt es eine Möglichkeit, den händischen Eingriff auf allen Clients zu vermeiden? (Auf den Clients ist noch der opsi-client-agent 4.0.6.3-13 installiert)

Danke und Gruß
Tobi

[n.wenselowski]

Hi,

du kannst auf deinen Clients die gespeicherten Zertifikate mit deleteServerCerts löschen und dann sollte es wieder gehen.
Ich würde allerdings erstmal ins Log der Clients und des Servers schauen, was genau das Problem ist. Hast du serverseitig eine Meldung Failed to process opsi service verification key in den Logs?


Gruß

Niko

[tobi]

Hi,

du kannst auf deinen Clients die gespeicherten Zertifikate mit deleteServerCerts löschen und dann sollte es wieder gehen.

mit deleteServerCerts lassen sich zwar die Zertifikate löschen, danach holt er sich aber die gleichen wieder ab und der Fehler bleibt bestehen.

Hast du serverseitig eine Meldung Failed to process opsi service verification key in den Logs?

Im Logfile finde ich Folgendes:
Failed to process opsi service verification key: data greater than mod len (workers.py|403)

Vielen Dank schon einmal für die Unterstützung.
Gruß
Tobi

[n.wenselowski]

Hi Tobi,

wie wurde das Zertifikat erstellt?
Auf welchem OS läuft der Server?
Welche Version von opsiconfd und python-opsi sind installiert?

Kannst du mir ein paar Zeilen mehr des opsiconfd-Logs mit Log-Level 8 posten, damit ich Kontext zum Fehler bekomme?


Gruß

Niko

[tobi]

Hi Niko,

wie wurde das Zertifikat erstellt?

Das Zertifikat (/etc/opsi/opsiconfd.pem) wurde automatisch durch das Paket opsiconfd erstellt (postinst) und lief seit 2014 einwandfrei.
(Das Neuerzeugen des Zertifikats durch löschen und apt-get install opsiconfd --reinstall und deleteServerCerts hat keine Änderung gebracht)

Auf welchem OS läuft der Server?

Debian Wheezy 64bit

Welche Version von opsiconfd und python-opsi sind installiert?

opsiconfd 4.0.7.4-1
python-opsi 4.0.7.17-11

Kannst du mir ein paar Zeilen mehr des opsiconfd-Logs mit Log-Level 8 posten, damit ich Kontext zum Fehler bekomme?

Hier der komplette Auszug mit Level 8.
Der Windows Client hat installiert:
opsi-client-agent 4.0.6.3-13
opsi-winst 4.11.5.20-2

Code: Alles auswählen

13:28:07] Now using log-file '/var/log/opsi/opsiconfd/192.168.1.68.log' for object 0x4f7c0e0 (Logger.py|453)
(7951)    [4] [Sep 14 13:28:07] Failed to read opsi modules file '/etc/opsi/modules': [Errno 2] No such file or directory: u'/etc/opsi/modules' (Backend.py|421)
(7952)    [6] [Sep 14 13:28:07] Worker <opsiconfd.workers.WorkerOpsiconfdJsonRpc instance at 0x4f7c0e0> started processing (Worker.py|251)
(7953)    [5] [Sep 14 13:28:07] Application 'opsiclientd version 4.0.83' on client '192.168.1.68' did not send cookie (workers.py|166)
(7954)    [7] [Sep 14 13:28:07] Trying to get username and password from Authorization header (workers.py|90)
(7955)    [7] [Sep 14 13:28:07] Authorization header found (type: opsi) (workers.py|94)
(7956)    [2] [Sep 14 13:28:07] Traceback: (Logger.py|753)
(7957)    [2] [Sep 14 13:28:07]   File "/usr/lib/pymodules/python2.7/opsiconfd/workers.py", line 102, in _getAuthorization
(7958)        self.service.config['sslServerKeyFile']), 'latin-1').strip()
(7959)     (Logger.py|753)
(7960)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/OPSI/Util/__init__.py", line 635, in decryptWithPrivateKeyFromPEMFile
(7961)        return ''.join(decrypt())
(7962)     (Logger.py|753)
(7963)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/OPSI/Util/__init__.py", line 628, in decrypt
(7964)        decr = privateKey.private_decrypt(data=''.join(parts), padding=padding)
(7965)     (Logger.py|753)
(7966)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/M2Crypto/RSA.py", line 63, in private_decrypt
(7967)        return m2.rsa_private_decrypt(self.rsa, data, padding)
(7968)     (Logger.py|753)
(7969)    [2] [Sep 14 13:28:07]      ==>>> data greater than mod len (workers.py|104)
(7970)    [3] [Sep 14 13:28:07] Bad Authorization header from '192.168.1.68': data greater than mod len (workers.py|119)
(7971)    [8] [Sep 14 13:28:07] WorkerOpsiconfdJsonRpc._errback (Worker.py|283)
(7972)    [7] [Sep 14 13:28:07] <opsiconfd.workers.WorkerOpsiconfdJsonRpc instance at 0x4f7c0e0>._setCookie (Worker.py|422)
(7973)    [6] [Sep 14 13:28:07] Adding header x-opsi-service-verification-key (workers.py|393)
(7974)    [2] [Sep 14 13:28:07] Traceback: (Logger.py|753)
(7975)    [2] [Sep 14 13:28:07]   File "/usr/lib/pymodules/python2.7/opsiconfd/workers.py", line 398, in _processOpsiServiceVerificationKey
(7976)        [decryptWithPrivateKeyFromPEMFile(base64.decodestring(value[0]), self.service.config['sslServerKeyFile'])]
(7977)     (Logger.py|753)
(7978)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/OPSI/Util/__init__.py", line 635, in decryptWithPrivateKeyFromPEMFile
(7979)        return ''.join(decrypt())
(7980)     (Logger.py|753)
(7981)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/OPSI/Util/__init__.py", line 628, in decrypt
(7982)        decr = privateKey.private_decrypt(data=''.join(parts), padding=padding)
(7983)     (Logger.py|753)
(7984)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/M2Crypto/RSA.py", line 63, in private_decrypt
(7985)        return m2.rsa_private_decrypt(self.rsa, data, padding)
(7986)     (Logger.py|753)
(7987)    [2] [Sep 14 13:28:07]      ==>>> data greater than mod len (workers.py|402)
(7988)    [3] [Sep 14 13:28:07] Failed to process opsi service verification key: data greater than mod len (workers.py|403)
(7989)    [2] [Sep 14 13:28:07] Traceback: (Logger.py|753)
(7990)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/OPSI/Service/Worker.py", line 292, in _errback
(7991)        failure.raiseException()
(7992)     (Logger.py|753)
(7993)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 551, in _runCallbacks
(7994)        current.result = callback(current.result, *args, **kw)
(7995)     (Logger.py|753)
(7996)    [2] [Sep 14 13:28:07]   File "/usr/lib/pymodules/python2.7/opsiconfd/workers.py", line 174, in _getSession
(7997)        WorkerOpsi._getSession(self, result)
(7998)     (Logger.py|753)
(7999)    [2] [Sep 14 13:28:07]   File "/usr/lib/python2.7/dist-packages/OPSI/Service/Worker.py", line 391, in _getSession
(8000)        sessionId = self._getSessionId()
(8001)     (Logger.py|753)
(8002)    [2] [Sep 14 13:28:07]   File "/usr/lib/pymodules/python2.7/opsiconfd/workers.py", line 428, in _getSessionId
(8003)        return WorkerOpsiconfd._getSessionId(self)
(8004)     (Logger.py|753)
(8005)    [2] [Sep 14 13:28:07]   File "/usr/lib/pymodules/python2.7/opsiconfd/workers.py", line 169, in _getSessionId
(8006)        raise OpsiAuthenticationError(u"Application '%s' on client '%s' did neither supply session id nor password" % (self._getUserAgent(), self.request.remoteAddr.host))
(8007)     (Logger.py|753)
(8008)    [2] [Sep 14 13:28:07]      ==>>> Opsi authentication error: Application 'opsiclientd version 4.0.83' on client '192.168.1.68' did neither supply session id nor password (Worker.py|294)

Bei den Clients handelt es sich um Windows 7 64bit Rechner.

Was mir noch aufgefallen ist:
Wenn ich auf einem Client durch setzen von verify_server_cert auf false die neuste Version von opsi-client-agent (4.0.7.7-1) installiere, läuft erstmal alles wieder richtig. Wenn ich dann aber die Variable opsiclientd.global.verify_server_cert auf true setze und der Client dies übernommen hat, hängt sich dieser beim nächsten Connect auf und bleibt mit der Meldung "Verbinde zu Config-Server '...' #1 Timeout 10s" stehen. Dies läßt sich mit Alt-F4 schließen.

Gruß
Tobi

[tobi]

Hi,

ich habe ein paar neue Erkenntnisse die vielleicht helfen können:

Ein Fehler liegt vermutlich in der Funktion decryptWithPrivateKeyFromPEMFile. Habe daher mal testweise die Datei /usr/share/pyshared/OPSI/Util/__init__.py mit einer älteren ersetzt, compiled und opsiconfd neugestartet.
Seitdem connecten die Clients wieder ohne Fehler, auch mit eingeschaltetem verify_server_cert (zumindest die mit opsi-client-agent 4.0.6.3-13, die neue Version hängt sich weiterhin auf)

Weiterhin ist mir aufgefallen, daß die Zertifikate aus dem debian postinst-Skript eine Länge von 1024 haben. Wenn man mit opsi-setup --renew-opsiconfd-cert ein neues generiert, entsteht eins mit 2048 bit. Hat das Problem hiermit was zu tun?

Das Problem mit dem neuen opsi-client-agent (4.0.7.7-1) scheint ein komplett anderes zu sein bei eingeschaltetem verify_server_cert . Hier beendet sich wohl der Dienst opsiclientd, die Fenster bleiben allerdings offen.


Hoffe daß ihr mit den Informationen was anfangen könnt.

Danke und Gruß
Tobi

[ueluekmen]

Vielen Dank für deine Antwort. Jetzt wird einiges klarer.

Weiterhin ist mir aufgefallen, daß die Zertifikate aus dem debian postinst-Skript eine Länge von 1024 haben. Wenn man mit opsi-setup --renew-opsiconfd-cert ein neues generiert, entsteht eins mit 2048 bit. Hat das Problem hiermit was zu tun?

Das werden wir korrigieren. Das new-cert ist natürlich das aktuellere. Wir beheben das in den Paketen beim nächsten Release.

decryptWithPrivateKeyFromPEMFile

Wir mussten diese Methode ändern, da diese in der alten Fassung ein Segmentationfault im SSL-Modul verursacht. Deshalb ist die Log auch abrupt vorbei, weil der Absturz viel tiefer passiert. Das wir dabei den alten Client bei verify_server_cert kaputt gemacht haben, war uns nicht bewusst. Ich war mir sicher, dass wir das intensiv getestet haben, aber an der Stelle scheint uns etwas durch die Lappen gegangen zu sein. Auch hier die Empfehlung von uns:

viewtopic.php?f=6&t=8625&start=20#p38082