Update to 8.0.15: M2Crypto.SSL.SSLError: wrong version number

[arrabito]

Dear all,

We were running DIRAC version 8.0.5 and I tried to update our servers to 8.0.15.

However, even if most of the services seem to run fine, I have troubles with the CS.

In the logs of the CS, it seems to work fine, but regularly there are error messages:

M2Crypto.SSL.SSLError: wrong version number

(see more details below)

Moreover, I'm not able to display the sections of the CS from the web portal. Each time I try to expand a section I get:

There is no connection established with the server.
Do you want to reconnect now? 

I tried to revert back to the version 8.0.5, but I still get the same error as before.

Any idea of what is going wrong?

Thank you.

Log:

2023-03-03 07:08:21 UTC Unknown/TornadoConfigurationHandler [140479244068672] NOTICE: Returning response (141.34.51.42:55526)[hosts:disp-vm1.zeuthen.desy.de] Configuration/Server (5.19 ms) OK
ERROR:tornado.general:Uncaught exception, closing connection.
Traceback (most recent call last):
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado/iostream.py", line 711, in _handle_events
    self._handle_read()
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado/iostream.py", line 1616, in _handle_read
    self._do_ssl_handshake()
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado_m2crypto/m2iostream.py", line 175, in _do_ssl_handshake
    res = self.socket.accept_ssl()
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/M2Crypto/SSL/Connection.py", line 275, in accept_ssl
    return m2.ssl_accept(self.ssl, self._timeout)
M2Crypto.SSL.SSLError: wrong version number
ERROR:asyncio:Exception in callback None()
handle: <Handle cancelled>
Traceback (most recent call last):
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado/platform/asyncio.py", line 122, in _handle_events
    handler_func(fileobj, events)
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado/stack_context.py", line 300, in null_wrapper
    return fn(*args, **kwargs)
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado/iostream.py", line 711, in _handle_events
    self._handle_read()
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado/iostream.py", line 1616, in _handle_read
    self._do_ssl_handshake()
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/tornado_m2crypto/m2iostream.py", line 175, in _do_ssl_handshake
    res = self.socket.accept_ssl()
  File "/opt/dirac/versions/v2.2.0a2-1672756588/Linux-x86_64/lib/python3.9/site-packages/M2Crypto/SSL/Connection.py", line 275, in accept_ssl
    return m2.ssl_accept(self.ssl, self._timeout)
M2Crypto.SSL.SSLError: wrong version number

[arrabito]

As a further detail, the connection to CS from a client seems to work fine, but the connection to the CS Manager from the web portal still fails.

[arrabito]

It seems that the problem I have with the connection to the CS Manager web app is not related to the M2Crypto.SSL.SSLError: wrong version number
error.

At least I don't see a correlation between the timestamps of these errors and the fact that I cannot use the CS Manager web app.

[chaen]

wrong version number is quite a generic error. if you want more debug message, use DIRAC_DEBUG_M2CRYPTO (https://dirac.readthedocs.io/en/latest/AdministratorGuide/ServerInstallations/environment_variable_configuration.html)

[arrabito]

Thank you @chaen I've added this variable and I get more info, but as said before the problem I have with the CS Manager web app does not seem related to this.

Currently I don't get the M2Crypto error anymore, maybe because I reverted back to 8.0.5, but the problem with the web app persists.

Here below anyway some logs of the CS:

2023-03-03 08:18:12 UTC Unknown/TornadoConfigurationHandler [140628686591808] NOTICE: Returning response (141.34.51.42:55054)[hosts:disp-vm1.zeuthen.desy.de] Configuration/Server (4.76 ms) OK
ALERT: write: warning: close notify
LOOP: SSL accept: before SSL initialization
LOOP: SSL accept: before SSL initialization
LOOP: SSL accept: SSLv3/TLS read client hello
LOOP: SSL accept: SSLv3/TLS write server hello
LOOP: SSL accept: SSLv3/TLS write change cipher spec
LOOP: SSL accept: TLSv1.3 write encrypted extensions
LOOP: SSL accept: SSLv3/TLS write certificate request
LOOP: SSL accept: SSLv3/TLS write certificate
LOOP: SSL accept: TLSv1.3 write server certificate verify
LOOP: SSL accept: SSLv3/TLS write finished
LOOP: SSL accept: TLSv1.3 early data
INFO: SSL accept: TLSv1.3 early data
INFO: SSL accept: TLSv1.3 early data
LOOP: SSL accept: TLSv1.3 early data
LOOP: SSL accept: SSLv3/TLS read client certificate
LOOP: SSL accept: SSLv3/TLS read certificate verify
LOOP: SSL accept: SSLv3/TLS read finished
LOOP: SSL accept: SSLv3/TLS write session ticket
LOOP: SSL accept: SSLv3/TLS write session ticket
INFO: SSL accept: SSL negotiation finished successfully
2023-03-03 08:18:14 UTC Unknown/TornadoConfigurationHandler [140628499572480] DEBUG: SSL authentication success.
2023-03-03 08:18:14 UTC Unknown/Authorization [140628499572480] DEBUG: Trying to authenticate DN=/DC=org/DC=terena/DC=tcs/C=DE/ST=Hamburg/O=Deutsches Elektronen-Synchrotron DESY/CN=disp-vm1.zeuthen.desy.de extraCredentials=hosts
2023-03-03 08:18:14 UTC Unknown/Authorization [140628499572480] DEBUG: Method getCompressedData has no properties defined using /Default
2023-03-03 08:18:14 UTC Unknown/TornadoConfigurationHandler [140628507965184] NOTICE: Incoming request (141.34.51.42:55158)[hosts:disp-vm1.zeuthen.desy.de] Configuration/Server: getCompressedData
2023-03-03 08:18:14 UTC Unknown/TornadoConfigurationHandler [140628686591808] NOTICE: Returning response (141.34.51.42:55158)[hosts:disp-vm1.zeuthen.desy.de] Configuration/Server (4.77 ms) OK
ALERT: write: warning: close notify

[chaen]

you should look at the logs on the webapp side

[arrabito]

Yes that's what I've done.
There is no log, no response when I click on the CS Manager while it works fine for all other monitors.

[chaen]

what webapp version do you have ?

[arrabito]

5.0.3

[chaen]

Probably updating would help: DIRACGrid/WebAppDIRAC#715

[fstagni]

Is this the version you have now (after downgrading from 8.0.15 to 8.0.5) or the version that was there before downgrading?

[arrabito]

5.0.3 is the version I have after downgrading to 8.0.5.

[arrabito]

While on our production server (which is working fine) we have:

DIRAC 8.0.5
WebAppDIRAC 5.0.1

So I've also tried this combination but it does not work.

[arrabito]

Comparing the logs of the WebApp with those on a working instance I've noticed that there is no message about contacting the:
Framework/UserProfileManager

[chaen]

Did you do that ? https://github.com/DIRACGrid/DIRAC/wiki/DIRAC-8.0#userprofile

[arrabito]

No... When we updated to 8.0.5 there was no such note. I guess it was added after and I haven't thought to check the release notes again. I'm going to apply that and let you know.

[arrabito]

I've done:

USE UserProfileDB;
ALTER Table `up_Users` MODIFY COLUMN UserName VARCHAR(64);

then we did not need to apply any fix to the up_ProfilesData table since it's empty in our case.

However this change did not solve the issue.

[arrabito]

I've updated WebAppDIRAC to 5.0.5 but it did not help.

The strange thing is that also reverting back to the versions that we were using before, i.e.:

DIRAC 8.0.5
WebAppDIRAC 5.0.1

The CS Manager web app is broken.

[chaen]

Hard to help any further than this.
I would hack the WebApp handler to point to a specific CS URL that you run by hand on another server in debug mode, to see what actually happens.

[arrabito]

I understand that it's difficult to debug further remotely.
Anyway I've done what you suggested and I see no trace of connection to the CS in the logs of the pointed CS when I try to use the CS Manager. The same happens also for the RegistryManager, so I thought that the fix you pointed out (included in the latest 5.0.5) would have helped but it's not the case.
Let me add that we see my connection attempts in nginx logs but not in the WebApp, neither in the CS logs.

[chaen]

The fact that both the CS and the registry are impacted really makes me believe that your problem is solved in 5.0.5.
When you install the latest webapp, can you try not only to restart the webapp, but to literally kill it (kill -9) to make sure it picks up the latest files ?

[fstagni]

Hello, I don't see recent replies in this thread. Was it sorted out?

[arrabito]

Thank you for following this.
We have been able to make it working by redoing the full DIRAC server (and also WebApp) installation from scratch.
The current versions installed are:
DIRAC = 8.0.15
WebAppDIRAC=5.0.7