Bad Magic - stunnel-users

21 Feb 2017


I'm trying to do a proof of concept using Stunnel on AIX 6.1.
Without stunnel I'd have:
Telnet session -> listening service
With stunnel, I want:
telnet session -> stunnel client -[secure connection]--> Stunnel server -->listening service.
The stunnel client seems to be working fine, but the stunnel server abends as soon as it receives a secure connection.
Client:
Accepts non-secure on port 33342. Forwards to secure socket 33343
stunnel stunnel.conf.2
2017.02.21 09:31:35 LOG5[ui]: stunnel 5.40 on powerpc-ibm-aix6.1.0.0 platform
2017.02.21 09:31:35 LOG5[ui]: Compiled/running with OpenSSL 1.0.2j 26 Sep 2016
2017.02.21 09:31:35 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,FIPS,OCSP,PSK,SNI
2017.02.21 09:31:35 LOG5[ui]: Reading configuration from file /bmo/stunnel/bin/stunnel.conf.2
2017.02.21 09:31:35 LOG5[ui]: UTF-8 byte order mark detected
2017.02.21 09:31:35 LOG5[ui]: FIPS mode disabled
2017.02.21 09:31:35 LOG6[ui]: Initializing service [hif]
2017.02.21 09:31:35 LOG6[ui]: Loading certificate from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:35 LOG6[ui]: Certificate loaded from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:35 LOG6[ui]: Loading private key from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:35 LOG4[ui]: Insecure file permissions on /bmo/stunnel/stunnel.pem
2017.02.21 09:31:35 LOG6[ui]: Private key loaded from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:35 LOG4[ui]: Service [hif] needs authentication to prevent MITM attacks
2017.02.21 09:31:35 LOG5[ui]: Configuration successful
2017.02.21 09:31:38 LOG5[0]: Service [hif] accepted connection from 127.0.0.1:34749
2017.02.21 09:31:38 LOG6[0]: s_connect: connecting 127.0.0.1:33343
2017.02.21 09:31:38 LOG6[0]: s_connect: connected 127.0.0.1:33343
2017.02.21 09:31:38 LOG5[0]: Service [hif] connected remote server from 127.0.0.1:34750
2017.02.21 09:31:38 LOG6[0]: SNI: sending servername: localhost
2017.02.21 09:31:38 LOG6[0]: Peer certificate not required
2017.02.21 09:31:38 LOG3[0]: SSL_connect: Peer suddenly disconnected
2017.02.21 09:31:38 LOG5[0]: Connection reset: 0 byte(s) sent to TLS, 0 byte(s) sent to socket
Server
Accepts SSL connections on port 33343, connects to a non-secure service.
stunnel stunnel.conf.1
2017.02.21 09:31:25 LOG5[ui]: stunnel 5.40 on powerpc-ibm-aix6.1.0.0 platform
2017.02.21 09:31:25 LOG5[ui]: Compiled/running with OpenSSL 1.0.2j 26 Sep 2016
2017.02.21 09:31:25 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,FIPS,OCSP,PSK,SNI
2017.02.21 09:31:25 LOG5[ui]: Reading configuration from file /bmo/stunnel/bin/stunnel.conf.1
2017.02.21 09:31:25 LOG5[ui]: UTF-8 byte order mark detected
2017.02.21 09:31:25 LOG5[ui]: FIPS mode disabled
2017.02.21 09:31:25 LOG6[ui]: Initializing service [hif]
2017.02.21 09:31:25 LOG6[ui]: Loading certificate from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:25 LOG6[ui]: Certificate loaded from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:25 LOG6[ui]: Loading private key from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:25 LOG4[ui]: Insecure file permissions on /bmo/stunnel/stunnel.pem
2017.02.21 09:31:25 LOG6[ui]: Private key loaded from file: /bmo/stunnel/stunnel.pem
2017.02.21 09:31:25 LOG5[ui]: Configuration successful
2017.02.21 09:31:38 LOG5[0]: Service [hif] accepted connection from 127.0.0.1:34750
2017.02.21 09:31:38 LOG6[0]: Peer certificate not required
INTERNAL ERROR: Bad magic at OpenSSL, line 0
(this is an abend - core file gets created).
log file exactly matches the standard output.
Any idea what's going wrong here?
dbx of the core file:
tbs@netcbccadvwvr01 /bmo/hif/stunnel-5.40/src>dbx /bmo/stunnel/bin/stunnel core
Type 'help' for help.
[using memory image in core]
reading symbolic information ...
IOT/Abort trap in abort at 0xd01af1f8 ($t3)
0xd01af1f8 (abort+0xf8) 80410014 lwz r2,0x14(r1)
(dbx) where
abort() at 0xd01af1f8
fatal_debug(txt = "Bad magic", file = "OpenSSL", line = 0), line 359 in "log.c"
get_alloc_list_ptr(ptr = 0x2007e1c8, file = "OpenSSL", line = 0), line 399 in "str.c"
str_detach_debug(ptr = 0x2007e1c8, file = "OpenSSL", line = 0), line 348 in "str.c"
str_free_debug(ptr = 0x2007e1c8, file = "OpenSSL", line = 0), line 383 in "str.c"
free_function(ptr = 0x2007e1c8), line 191 in "tls.c"
mem.CRYPTO_free() at 0xd97dd8d8
bn_lib.bn_expand2@AF37_5() at 0xd97e8da4
bn_mont.BN_mod_mul_montgomery() at 0xd981e150
ecp_mont.ec_GFp_mont_field_mul() at 0xd9837a18
ecp_smpl.ec_GFp_simple_point_get_affine_coordinates() at 0xd9839890
ec_lib.EC_POINT_get_affine_coordinates_GFp() at 0xd9a81dfc
ecp_oct.ec_GFp_simple_point2oct() at 0xd9acc0d4
ec_oct.EC_POINT_point2oct() at 0xd9acb754
ssl3_send_server_key_exchange() at 0xd99e7c28
ssl3_accept() at 0xd99e9950
SSL_accept() at 0xd99c0b98
ssl23_get_client_hello() at 0xd9a003f4
ssl23_accept() at 0xd9a00c5c
SSL_accept() at 0xd99c0b98
ssl_start(c = 0x20084cb8), line 431 in "client.c"
client_try(c = 0x20084cb8), line 273 in "client.c"
client_run(c = 0x20084cb8), line 181 in "client.c"
client_main(c = 0x20084cb8), line 140 in "client.c"
client_thread(arg = 0x20084cb8), line 99 in "client.c"
(dbx) thread
thread state-k wchan state-u k-tid mode held scope function
$t1 run running 26279997 u no sys __fd_poll
$t2 run running 45088879 u no sys _p_nsleep
...
$t3 run running 19070997 k no sys abort
(dbx) list free_function
186
187 #if OPENSSL_VERSION_NUMBER<0x10100000L
188 NOEXPORT void free_function(void *ptr) {
189 /* CRYPTO_set_mem_ex_functions() needs a function rather than a macro */
190 /* unfortunately, OpenSSL provides no file:line information here */
191 str_free_debug(ptr, "OpenSSL", 0);
192 }
193 #endif
194
195 /* end of tls.c */
Should I be concerned that it looks like it is executing "free_function" from within an if statement "if OPENSSL_VERSION_NUMBER<0x1010000L but my openssl version is
2017.02.21 09:31:35 LOG5[ui]: Compiled/running with OpenSSL 1.0.2j 26 Sep 2016
Troubleshooting so far:
- I had the same problem with earlier versions of openssl.
- I've tried this with 5.37 as well (based on Brian McGinity's post from a few days ago), but get the same error.
Jacob