[RADIATOR] Fwd: Re: Problem with Radsec connections

Tue Nov 5 12:10:22 UTC 2019

Hi, 

Have checked our config (once again ;)) and everything looks fine. All
the cert's are ok and every TLS_* config points to a valid file or a
valid config. 

The startup logs points to no errors, as you can see bellow: 

Tue Nov 5 03:33:01 2019 191659: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 191684: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 191672: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 191675: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 191694: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 191676: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 191693: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 191744: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:01 2019 200317: DEBUG: Stream disconnected from
localhost (client.ip.v4.address:2083)
Tue Nov 5 03:33:01 2019 202821: DEBUG: Sending TERM signal to server
farm child 435475
Tue Nov 5 03:33:01 2019 212230: DEBUG: Sending TERM signal to server
farm child 435474
Tue Nov 5 03:33:01 2019 212484: DEBUG: Sending TERM signal to server
farm child 435468
Tue Nov 5 03:33:01 2019 212674: DEBUG: Sending TERM signal to server
farm child 435473
Tue Nov 5 03:33:01 2019 212846: DEBUG: Sending TERM signal to server
farm child 435470
Tue Nov 5 03:33:01 2019 213015: DEBUG: Sending TERM signal to server
farm child 435469
Tue Nov 5 03:33:01 2019 213192: DEBUG: Sending TERM signal to server
farm child 435471
Tue Nov 5 03:33:01 2019 213359: DEBUG: Sending TERM signal to server
farm child 435472
Tue Nov 5 03:33:01 2019 251995: DEBUG: Terminated Server farm child
435475
Tue Nov 5 03:33:01 2019 253195: DEBUG: Terminated Server farm child
435470
Tue Nov 5 03:33:01 2019 255612: DEBUG: Terminated Server farm child
435472
Tue Nov 5 03:33:01 2019 256689: DEBUG: Terminated Server farm child
435468
Tue Nov 5 03:33:01 2019 256801: DEBUG: Terminated Server farm child
435473
Tue Nov 5 03:33:01 2019 257294: DEBUG: Terminated Server farm child
435474
Tue Nov 5 03:33:01 2019 257404: DEBUG: Terminated Server farm child
435469
Tue Nov 5 03:33:01 2019 257689: DEBUG: Terminated Server farm child
435471
Tue Nov 5 03:33:01 2019 259308: NOTICE: SIGTERM received: stopping
Tue Nov 5 03:33:31 2019 823968: DEBUG: include
/etc/radiator/peers/REJEITA.cfg
... several peer include configuration files ... 
Tue Nov 5 03:33:32 2019 139896: DEBUG: include
/etc/radiator/peers/Europe.cfg
Tue Nov 5 03:33:32 2019 142318: DEBUG: Radius::JSON backend is JSON::XS
version 3.01
Tue Nov 5 03:33:32 2019 142440: DEBUG: SCTP socket API extensions not
available
Tue Nov 5 03:33:32 2019 142528: DEBUG: Finished reading configuration
file '/etc/radiator/radiator.conf'
Tue Nov 5 03:33:32 2019 390272: DEBUG: Initialised SSL library:
Net::SSLeay 1.88, OpenSSL 1.1.1c 28 May 2019
Tue Nov 5 03:33:32 2019 390529: INFO: Using Net::SSLeay 1.88 with
SSL/TLS library version 0x1010103f (OpenSSL 1.1.1c 28 May 2019)
Tue Nov 5 03:33:32 2019 390630: DEBUG: SSL/TLS library and Net::SSLeay
support set_default_passwd_cb and related functions
Tue Nov 5 03:33:32 2019 391943: DEBUG: TLS: Using 0x2 (2) for
Net::SSLeay constant TLSEXT_ERR_ALERT_FATAL
Tue Nov 5 03:33:32 2019 392318: DEBUG: TLS: Using 0x1 (1) for
Net::SSLeay constant TLSEXT_ERR_ALERT_WARNING
Tue Nov 5 03:33:32 2019 392641: DEBUG: TLS: Using 0x3 (3) for
Net::SSLeay constant TLSEXT_ERR_NOACK
Tue Nov 5 03:33:32 2019 392954: DEBUG: TLS: Using 0x0 (0) for
Net::SSLeay constant TLSEXT_ERR_OK
Tue Nov 5 03:33:32 2019 393873: DEBUG: Radius::ServerRADSEC RadSec
setting TLS_Ciphers to: DEFAULT:!EXPORT:!LOW
Tue Nov 5 03:33:32 2019 395322: DEBUG: (Re)loading CRL file
'/etc/radiator/cert/CRL/7da82b7c.r0'
Tue Nov 5 03:33:32 2019 395609: DEBUG: (Re)loading CRL file
'/etc/radiator/cert/CRL/c158e258.r0'
Tue Nov 5 03:33:32 2019 396300: DEBUG: Creating StreamServer listen
socket tcp port 2083 address my.ip.v4.address
Tue Nov 5 03:33:32 2019 416678: DEBUG: include
/etc/radiator/peers/REJEITA.cfg
... several peer include configuration files ... 
Tue Nov 5 03:33:32 2019 824475: DEBUG: include
/etc/radiator/peers/Europe.cfg
Tue Nov 5 03:33:32 2019 827133: DEBUG: Radius::JSON backend is JSON::XS
version 3.01
Tue Nov 5 03:33:32 2019 827259: DEBUG: SCTP socket API extensions not
available
Tue Nov 5 03:33:32 2019 827346: DEBUG: Finished reading configuration
file '/etc/radiator/radiator.conf'
Tue Nov 5 03:33:32 2019 827742: DEBUG: Reading dictionary file
'/etc/radiator/dictionary/dictionary'
Tue Nov 5 03:33:32 2019 968382: DEBUG: Reading dictionary file
'/etc/radiator/dictionary/dictionary.ascend'
Tue Nov 5 03:33:32 2019 970935: DEBUG: This system is IPv6 capable. IPv6
capability provided by: core
Tue Nov 5 03:33:32 2019 972124: DEBUG: Creating authentication port
my.ip.v4.address:1812
Tue Nov 5 03:33:32 2019 972358: DEBUG: Creating authentication port
my.ip.v4.address:1645
Tue Nov 5 03:33:32 2019 972516: DEBUG: Creating accounting port
my.ip.v4.address:1813
Tue Nov 5 03:33:32 2019 972663: DEBUG: Creating accounting port
my.ip.v4.address:1646
Tue Nov 5 03:33:32 2019 972806: DEBUG: Creating authentication port
my.ip.v6.address:1812
Tue Nov 5 03:33:32 2019 972952: DEBUG: Creating authentication port
my.ip.v6.address:1645
Tue Nov 5 03:33:32 2019 973089: DEBUG: Creating accounting port
my.ip.v6.address:1813
Tue Nov 5 03:33:32 2019 973234: DEBUG: Creating accounting port
my.ip.v6.address:1646
Tue Nov 5 03:33:32 2019 973375: DEBUG: Creating authentication port
127.0.0.1:1812
Tue Nov 5 03:33:32 2019 973508: DEBUG: Creating authentication port
127.0.0.1:1645
Tue Nov 5 03:33:32 2019 973640: DEBUG: Creating accounting port
127.0.0.1:1813
Tue Nov 5 03:33:32 2019 973771: DEBUG: Creating accounting port
127.0.0.1:1646
Tue Nov 5 03:33:32 2019 973924: NOTICE: Server started: Radiator 4.23 on
cv-radius.fccn.pt
Tue Nov 5 03:33:32 2019 974032: DEBUG: Forking server farm instance 1
Tue Nov 5 03:33:32 2019 975603: DEBUG: Forking server farm instance 2
Tue Nov 5 03:33:32 2019 977508: DEBUG: Forking server farm instance 3
Tue Nov 5 03:33:32 2019 979132: DEBUG: Forking server farm instance 4
Tue Nov 5 03:33:32 2019 980755: DEBUG: Forking server farm instance 5
Tue Nov 5 03:33:32 2019 982355: DEBUG: Forking server farm instance 6
Tue Nov 5 03:33:32 2019 983397: DEBUG: StreamServer: New connection from
client.ip.v4.address:47960
Tue Nov 5 03:33:32 2019 983979: DEBUG: Forking server farm instance 7
Tue Nov 5 03:33:32 2019 985282: DEBUG: Stream connected to
client.ip.v4.address (client.ip.v4.address:47960)
Tue Nov 5 03:33:32 2019 985655: DEBUG: Forking server farm instance 8
Tue Nov 5 03:33:32 2019 985932: DEBUG: StreamTLS sessionInit for
client.ip.v4.address
Tue Nov 5 03:33:32 2019 985463: DEBUG: StreamServer: New connection from
client.ip.v4.address:47963
Tue Nov 5 03:33:32 2019 986997: DEBUG: Stream connected to
client.ip.v4.address (client.ip.v4.address:47963)
Tue Nov 5 03:33:32 2019 987167: DEBUG: StreamServer: New connection from
client.ip.v4.address:47971
Tue Nov 5 03:33:32 2019 987533: DEBUG: StreamTLS sessionInit for
client.ip.v4.address
Tue Nov 5 03:33:32 2019 987950: DEBUG: StreamTLS receive: 
Tue Nov 5 03:33:32 2019 988293: DEBUG: StreamTLS SSL_accept result: -1,
2, 0
Tue Nov 5 03:33:32 2019 988347: DEBUG: Stream connected to
client.ip.v4.address (client.ip.v4.address:47971)
Tue Nov 5 03:33:32 2019 988760: DEBUG: StreamTLS sessionInit for
client.ip.v4.address
Tue Nov 5 03:33:32 2019 988798: DEBUG: StreamTLS send: 
Tue Nov 5 03:33:32 2019 988940: DEBUG: StreamTLS Server Started for
client.ip.v4.address (client.ip.v4.address:47960)
Tue Nov 5 03:33:32 2019 989027: DEBUG: New StreamServer Connection
created for client.ip.v4.address:47960
Tue Nov 5 03:33:32 2019 989217: DEBUG: StreamTLS receive:
16030100bc010000b803016202a244d5c58da9fa1e023790d60bed2abf4b800288189bf86545b4c7a6e98a00004ac014c00a0039003800880087c00fc00500350084c013c00900330032009a009900450044c00ec004002f00960041c011c007c00cc00200050004c012c00800160013c00dc003000a00ff01000045000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011000f000101

We have this configuration on another machine, but there are some
diferences, regarding the software vresions: 

 	* Tue Nov  5 03:35:04 2019: INFO: Using Net::SSLeay 1.66 with SSL/TLS
library version 0x1000105f (OpenSSL 1.0.1e-fips 11 Feb 2013)
 	* Tue Nov  5 03:35:04 2019: NOTICE: Server started: Radiator 4.19 on
cv2-radius.fccn.pt

Besides the version of Radiator, the OpenSSL and the Net::SSLeay are
also older. 

Pedro Simões

On 31/10/2019 18.23, Pedro Simões wrote:

> After an upgrade from a VM to a physical machine, we started having problems with Radsec on Radiator (This is Radiator 4.23).
> 
> From what we have managed to find, when we try to start a connection to a remote Radsec radius the first steps occurs, and we receive a reply.
> 
> At the second communication, when we tries to send the public part of our certificate an error occurs.

I would check the TLS_* configuration variables and see that all files
exists that the variables refer to.

> On our Radiator we have the following message, referring a Net::SSLeay error:
> 
> Wed Oct 30 03:38:28 2019 698096: ERR: StreamTLS could not create SSL: Net::SSLeay::new failed: 284759: 1 - error:140BA0C3:SSL routines:SSL_new:null ssl ctx

Can you check your log file starting from Radiator start. Are there any
error messages that preceed this problem. It seems that OpenSSL CTX
structure, from which structures for individual SSL connections are
created from, is not correctly set up.

> ,Inappropriate ioctl for device

This is system errno related string. I'd say this is not relevant on
your case.

> There is some strange thing that we have found. The connection first is sent to 193.136.195.229 and after that is referred as localhost (localhost (193.136.195.229:2083)).

This seems to be caused by dynamically created AuthBy RADSEC not
resetting default name that the TCP stream is connecting to. This
appears to be just confusing debugging and not related to, for example,
something trying to connect to 'localhost'.

To summarise: I'd check the previous log messages to see if there are
any problems leading to Net::SSLeay::new() error.

Thanks,
Heikki

-- 
Heikki Vatiainen <hvn at open.com.au>

Radiator: the most portable, flexible and configurable RADIUS server
anywhere. SQL, proxy, DBM, files, LDAP, TACACS+, PAM, Active Directory,
EAP, TLS, TTLS, PEAP, WiMAX, RSA, Vasco, Yubikey, HOTP, TOTP,
DIAMETER etc. Full source on Unix, Windows, MacOSX, Solaris, VMS, etc.
_______________________________________________
radiator mailing list
radiator at lists.open.com.au
https://lists.open.com.au/mailman/listinfo/radiator

-- 
_______________________________________________
Pedro Simões - psimoes at fccn.pt
Área de Serviços de Rede | Network Services Area
Eduroam | TCS | AAI
FCT|FCCN
Av. do Brasil, n.º 101
1700-066 Lisboa - Portugal
Telefone|Phone +351 218440100; Fax +351 218472167
www.fccn.pt [1] | www.eduroam.pt [2] || tcs.fccn.pt | rctsaai.fccn.pt 

Links:
------
[1] http://www.fccn.pt
[2] http://www.eduroam.pt
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.open.com.au/pipermail/radiator/attachments/20191105/3d1db033/attachment.html>