handshake fails

[Anders]

Hi

I have set up a galera environment with 3 masters and that works fine.
Now I want to use SSL for the communication between the servers. I
followed the instructions here: http://www.codership.com/wiki/doku.php?id=ssl_support

I keep getting "handshake failed". What am I missing?

Logs from first server started:

120211 19:53:21 [Note] WSREP: Quorum results:
version = 2,
component = PRIMARY,
conf_id = 0,
members = 1/1 (joined/total),
act_id = 118,
last_appl. = -1,
protocols = 0/1/1 (gcs/repl/appl),
group UUID = 23ac7203-4fe9-11e1-0800-6032ca00c9a2
120211 19:53:21 [Note] WSREP: Flow-control interval: [8, 16]
120211 19:53:21 [Note] WSREP: Restored state OPEN -> JOINED (118)
120211 19:53:21 [Note] WSREP: New cluster view: global state:
23ac7203-4fe9-11e1-0800-6032ca00c9a2:118, view# 1: Primary, number of
nodes: 1, my index: 0, protocol version 1
120211 19:53:21 [Note] WSREP: Member 0 (servername) synced with group.
120211 19:53:21 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 118)
120211 19:53:23 [Note] WSREP: Assign initial position for
certification: 118, protocol version: 1
120211 19:53:23 [Note] WSREP: Synchronized with group, ready for
connections
120211 19:58:50 [ERROR] WSREP: handshake failed for 0xa835fc0: 1
120211 19:58:52 [ERROR] WSREP: handshake failed for 0xa8473f0: 1
120211 19:58:53 [ERROR] WSREP: handshake failed for 0xa835fc0: 1
120211 19:58:55 [ERROR] WSREP: handshake failed for 0xa8473f0: 1


Logs from second server:

120211 19:58:49 mysqld_safe Starting mysqld daemon with databases
from /usr/local/mysql/data
120211 19:58:49 InnoDB: The InnoDB memory heap is disabled
120211 19:58:49 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120211 19:58:49 InnoDB: Compressed tables use zlib 1.2.3
120211 19:58:49 InnoDB: Using Linux native AIO
120211 19:58:49 InnoDB: Initializing buffer pool, size = 128.0M
120211 19:58:49 InnoDB: Completed initialization of buffer pool
120211 19:58:49 InnoDB: highest supported file format is Barracuda.
120211 19:58:49 InnoDB: Waiting for the background threads to start
120211 19:58:50 InnoDB: 1.1.8 started; log sequence number 1954697
120211 19:58:50 [Note] Event Scheduler: Loaded 0 events
120211 19:58:50 [Note] WSREP: wsrep_load(): loading provider library '/
usr/lib/galera/libgalera_smm.so'
120211 19:58:50 [Note] WSREP: wsrep_load(): Galera 22.1.1(r95) by
Codership Oy <in...@codership.com> loaded succesfully.
120211 19:58:50 [Note] WSREP: Reusing existing '/usr/local/mysql/data//
galera.cache'.
120211 19:58:50 [Note] WSREP: Passing config to GCS:
evs.consensus_timeout = PT1M; evs.inactive_check_period = PT10S;
evs.inactive_timeout = PT1M; evs.keepalive_period = PT3S;
evs.send_window = 1024; evs.suspect_timeout = PT30S;
evs.user_send_window = 512; gcache.dir = /usr/local/mysql/data/;
gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /usr/
local/mysql/data//galera.cache; gcache.page_size = 128M; gcache.size =
128M; gcs.fc_debug = 0; gcs.fc_factor = 0.5; gcs.fc_limit = 16;
gcs.fc_master_slave = NO; gcs.max_packet_size = 64500;
gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 2147483647;
gcs.recv_q_soft_limit = 0.25; replicator.commit_order = 3;
socket.ssl_cert = /conf/galeracert/cert.pem; socket.ssl_key = /conf/
galeracert/key.pem
120211 19:58:50 [Note] WSREP: Start replication
120211 19:58:50 [Note] WSREP: Found saved state:
23ac7203-4fe9-11e1-0800-6032ca00c9a2:118
120211 19:58:50 [Note] WSREP: Assign initial position for
certification: 118, protocol version: 1
120211 19:58:50 [Note] WSREP: Setting initial position to
23ac7203-4fe9-11e1-0800-6032ca00c9a2:118
120211 19:58:50 [Note] WSREP: protonet asio version 0
120211 19:58:50 [Note] WSREP: initializing ssl context
120211 19:58:50 [Note] WSREP: backend: asio
120211 19:58:50 [Note] WSREP: GMCast version 0
120211 19:58:50 [Note] WSREP: (6f46701a-54e2-11e1-0800-0a950abf2509,
'ssl://0.0.0.0:4567') listening at ssl://0.0.0.0:4567
120211 19:58:50 [Note] WSREP: (6f46701a-54e2-11e1-0800-0a950abf2509,
'ssl://0.0.0.0:4567') multicast: , ttl: 1
120211 19:58:50 [Note] WSREP: EVS version 0
120211 19:58:50 [Note] WSREP: PC version 0
120211 19:58:50 [Note] WSREP: gcomm: connecting to group
'my_wsrep_cluster', peer '<server_1>:4567'
120211 19:58:50 [ERROR] WSREP: handshake failed for 0x92b8058: 1
120211 19:58:52 [ERROR] WSREP: handshake failed for 0x92dee08: 1
120211 19:58:53 [ERROR] WSREP: handshake failed for 0x92dee08: 1

[Alex Yurchenko]

Hi,

It is not clear from the logs that you have configured SSL on the first
node. I think the problem might be there.

Regards,
Alex

--
Alexey Yurchenko,
Codership Oy, www.codership.com
Skype: alexey.yurchenko, Phone: +358-400-516-011

[Anders]

Hi,

I wish that was the case. Here's the rest of the log from the first
server:

120211 19:53:20 mysqld_safe Starting mysqld daemon with databases
from /usr/local/mysql/data
120211 19:53:20 InnoDB: The InnoDB memory heap is disabled
120211 19:53:20 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120211 19:53:20 InnoDB: Compressed tables use zlib 1.2.3
120211 19:53:20 InnoDB: Using Linux native AIO
120211 19:53:20 InnoDB: Initializing buffer pool, size = 128.0M
120211 19:53:20 InnoDB: Completed initialization of buffer pool
120211 19:53:20 InnoDB: highest supported file format is Barracuda.
120211 19:53:20 InnoDB: Waiting for the background threads to start
120211 19:53:21 InnoDB: 1.1.8 started; log sequence number 2156751
120211 19:53:21 [Note] Event Scheduler: Loaded 0 events
120211 19:53:21 [Note] WSREP: wsrep_load(): loading provider library '/
usr/lib/galera/libgalera_smm.so'
120211 19:53:21 [Note] WSREP: wsrep_load(): Galera 22.1.1(r95) by

Codership Oy <in...@codership.com> loaded succesfully.

120211 19:53:21 [Note] WSREP: Reusing existing '/usr/local/mysql/data//
galera.cache'.
120211 19:53:21 [Note] WSREP: Passing config to GCS:

evs.consensus_timeout = PT1M; evs.inactive_check_period = PT10S;
evs.inactive_timeout = PT1M; evs.keepalive_period = PT3S;
evs.send_window = 1024; evs.suspect_timeout = PT30S;
evs.user_send_window = 512; gcache.dir = /usr/local/mysql/data/;
gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /usr/
local/mysql/data//galera.cache; gcache.page_size = 128M; gcache.size =
128M; gcs.fc_debug = 0; gcs.fc_factor = 0.5; gcs.fc_limit = 16;
gcs.fc_master_slave = NO; gcs.max_packet_size = 64500;
gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 2147483647;
gcs.recv_q_soft_limit = 0.25; replicator.commit_order = 3;
socket.ssl_cert = /conf/galeracert/cert.pem; socket.ssl_key = /conf/
galeracert/key.pem

120211 19:53:21 [Note] WSREP: Start replication
120211 19:53:21 [Note] WSREP: Found saved state:
23ac7203-4fe9-11e1-0800-6032ca00c9a2:118
120211 19:53:21 [Note] WSREP: Assign initial position for

certification: 118, protocol version: 1

120211 19:53:21 [Note] WSREP: Setting initial position to
23ac7203-4fe9-11e1-0800-6032ca00c9a2:118
120211 19:53:21 [Note] WSREP: protonet asio version 0
120211 19:53:21 [Note] WSREP: initializing ssl context
120211 19:53:21 [Note] WSREP: backend: asio
120211 19:53:21 [Note] WSREP: GMCast version 0
120211 19:53:21 [Note] WSREP: (ab60df75-54e1-11e1-0800-4b3a62c70ec2,

'ssl://0.0.0.0:4567') listening at ssl://0.0.0.0:4567

120211 19:53:21 [Note] WSREP: (ab60df75-54e1-11e1-0800-4b3a62c70ec2,

'ssl://0.0.0.0:4567') multicast: , ttl: 1

120211 19:53:21 [Note] WSREP: EVS version 0
120211 19:53:21 [Note] WSREP: PC version 0
120211 19:53:21 [Note] WSREP: gcomm: connecting to group
'my_wsrep_cluster', peer ''
120211 19:53:21 [Note] WSREP: GMCast::handle_stable_view:
view(view_id(PRIM,ab60df75-54e1-11e1-0800-4b3a62c70ec2,1) memb {
ab60df75-54e1-11e1-0800-4b3a62c70ec2,
} joined {
} left {
} partitioned {
})
120211 19:53:21 [Note] WSREP: gcomm: connected
120211 19:53:21 [Note] WSREP: Changing maximum packet size to 64500,
resulting msg size: 32636
120211 19:53:21 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
120211 19:53:21 [Note] WSREP: Opened channel 'my_wsrep_cluster'
120211 19:53:21 [Note] /usr/local/mysql/bin/mysqld: ready for
connections.
Version: '5.5.17-log' socket: '/tmp/mysql.sock' port: 3306
wsrep_22.3.r3647
120211 19:53:21 [Note] WSREP: New COMPONENT: primary = yes, my_idx =
0, memb_num = 1
120211 19:53:21 [Note] WSREP: STATE_EXCHANGE: sent state UUID:
ab616b9f-54e1-11e1-0800-ecf7a41b3f3e
120211 19:53:21 [Note] WSREP: STATE EXCHANGE: sent state msg:
ab616b9f-54e1-11e1-0800-ecf7a41b3f3e
120211 19:53:21 [Note] WSREP: STATE EXCHANGE: got state msg:
ab616b9f-54e1-11e1-0800-ecf7a41b3f3e from 0 (servername)

120211 19:53:21 [Note] WSREP: Quorum results:

The cert and key was created on server 2 and copied to server 1.
Any suggestions?

Thanks,
Anders


On Feb 11, 9:08 pm, Alex Yurchenko <alexey.yurche...@codership.com>
wrote:

> > Codership Oy <i...@codership.com> loaded succesfully.

[Teemu Ollakka]

Hi Anders,

This is quite far fetched, but could you first check that pem files
are actually readable by mysql process?

If the files are readable, try to run

openssl s_client -host <server_1> -port 4567 -cert /conf/galeracert/
cert.pem -key /conf/galeracert/key.pem

on the second server. This should result something like

120215 19:01:25 [Note] WSREP: SSL handshake successful, remote
endpoint ssl://192.168.3.2:58980 local endpoint ssl://192.168.3.1:4567
cipher: AES128-SHA compression: zlib compression

in <server_1>'s log. If the handshake still fails, openssl output
should give further diagnostics what is going wrong.

- Teemu

[Anders]

Hi Teemu,

Perfect. That helped me to figure out the issue. It turned out that
the value I used for -days when generating the cert/key was too large.
Apparently you cannot specify the number of days so that the
certificate expire after year 2038.

Thank you for your help.
br,
Anders