TLS communication, EAP does not work
Edelberto Franco
esilva at midiacom.uff.br
Thu Jul 13 22:50:27 CEST 2017
Hi
I'm working with Luciano on eduroam BR and trying to solve this.
I attached our debug files.
4 files:
1) debug-eapol-from-ujfteste-to-rnpteste - the client eapol running an
auth test
2) debug-ufjfteste-FR3 - FreeRadius @ inst1/ufjfteste.br
3) debug-rnpteste-FR3 - FreeRadius @ inst1/rnpteste.br
4) debug-radsecproxy-FLR - radsecproxy @ federation level
What caught my attention was this "error" on the local (institution)
FreeRadius
rlm_eap (EAP): No EAP session matching state 0xc6ab1049c7a90598
I can send debug file from radtest too, but I think this isn't necessary
Thank you all
--Edelberto
Em 13-Jul-17 4:59 PM, Alan Buxey escreveu:
> not sure what you've done - I've used FreeRADIUS with native radsec
> connectivity to proxy EAP to remote servers (RADIATOR and radsecproxy)
> and to receive
> EAP from the same remote proxies. Would suggest, as Alan had said, to
> grab debug and check what the server is doing. its all quite clear
> what its
> doing (dont be overwhelmed by all the output, just read it step by
> step...) - there will be some very ovbious difference between the EAP
> and your radtest - likely
> to be related to action of server when packet has gone into
> inner-tunnel (which, I'm guessing it shouldnt be doing as its supposed
> to be proxied
> to remote site......)
>
> alan
>
> On 13 July 2017 at 15:23, Alan DeKok <aland at deployingradius.com> wrote:
>> On Jul 13, 2017, at 9:46 AM, Luciano Fernandes da Rocha <luciano.rocha at rnp.br> wrote:
>>>
>>> Briefly, our scenario has 3 servers with FreeRadius 3.0.14. 2 institutions (ufjfteste.br and rnpteste.br) and 1 FLR (.br). On the institution level we run RadSec (embedded TCP/TLS in FreeRadius3) to communicate with our FLR, a radsecproxy. So, using this TLS communication, EAP does not work, but turning off it and doing the communication between all servers using only UDP (disabling RadSec at institutions and radsecproxy at FLR), all EAP methods works.
>> Please be clearer about "it doesn't work". What happens? What does the debug say?
>>
>>> To confirm it, if we turn on the TLS communication, we could only authenticate using 'radtest' (as we know, a simple authentication without EAP).
>>>
>>> We suspect that EAP messages are lost during the exchanging when TLS communication are enable.
>> The server doesn't lose EAP messages.
>>
>>> Do you have any ideia about it to help us?
>> Read the debug output. Or, post it to the list. Nothing else will help.
>>
>> if it's too large to send on the list (~500K), send it to me off-list. Preferably gzip'd.
>>
>> Set up a proxy which uses RadSec to talk to a home server. Set up the home server with test certs and a test user. Use wpa_supplicant to send packets to the proxy.
>>
>> Then send ALL the debug output over.
>>
>> Alan DeKok.
>>
>>
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-------------- next part --------------
Reading configuration file 'ttls-pap-roaming.txt'
Line: 1 - start of a new network block
ssid - hexdump_ascii(len=7):
65 64 75 72 6f 61 6d eduroam
key_mgmt: 0x8
eap methods - hexdump(len=16): 00 00 00 00 15 00 00 00 00 00 00 00 00 00 00 00
pairwise: 0x8
phase2 - hexdump_ascii(len=8):
61 75 74 68 3d 50 41 50 auth=PAP
identity - hexdump_ascii(len=19):
65 64 75 72 6f 61 6d 40 72 6e 70 74 65 73 74 65 eduroam at rnpteste
2e 62 72 .br
password - hexdump_ascii(len=7):
65 64 75 72 6f 61 6d eduroam
Line 10: removed CCMP from group cipher list since it was not allowed for pairwise cipher
Priority group 0
id=0 ssid='eduroam'
Authentication server 127.0.0.1:1812
RADIUS local address: 127.0.0.1:49487
ENGINE: Loading dynamic engine
ENGINE: Loading dynamic engine
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: KEY_RX entering state NO_KEY_RECEIVE
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portValid=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
Sending fake EAP-Request-Identity
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_PAE entering state RESTART
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=0 method=1 vendor=0 vendorMethod=0
EAP: EAP entering state IDENTITY
CTRL-EVENT-EAP-STARTED EAP authentication started
EAP: Status notification: started (param=)
EAP: EAP-Request Identity data - hexdump_ascii(len=0):
EAP: using real identity - hexdump_ascii(len=19):
65 64 75 72 6f 61 6d 40 72 6e 70 74 65 73 74 65 eduroam at rnpteste
2e 62 72 .br
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
WPA: eapol_test_eapol_send(type=0 len=24)
TX EAP -> RADIUS - hexdump(len=24): 02 00 00 18 01 65 64 75 72 6f 61 6d 40 72 6e 70 74 65 73 74 65 2e 62 72
Encapsulating EAP message into a RADIUS packet
Learned identity from EAP-Response-Identity - hexdump(len=19): 65 64 75 72 6f 61 6d 40 72 6e 70 74 65 73 74 65 2e 62 72
Sending RADIUS message to authentication server
RADIUS message: code=1 (Access-Request) identifier=0 length=152
Attribute 1 (User-Name) length=21
Value: 'eduroam at rnpteste.br'
Attribute 4 (NAS-IP-Address) length=6
Value: 127.0.0.1
Attribute 31 (Calling-Station-Id) length=19
Value: '02-00-00-00-00-01'
Attribute 12 (Framed-MTU) length=6
Value: 1400
Attribute 61 (NAS-Port-Type) length=6
Value: 19
Attribute 6 (Service-Type) length=6
Value: 2
Attribute 77 (Connect-Info) length=24
Value: 'CONNECT 11Mbps 802.11b'
Attribute 79 (EAP-Message) length=26
Value: 0200001801656475726f616d40726e7074657374652e6272
Attribute 80 (Message-Authenticator) length=18
Value: 425dab3569ba0abc75b3ed0250beb9bd
Next RADIUS client retransmit in 3 seconds
EAPOL: SUPP_BE entering state RECEIVE
Received 80 bytes from RADIUS server
Received RADIUS message
RADIUS message: code=11 (Access-Challenge) identifier=0 length=80
Attribute 79 (EAP-Message) length=24
Value: 010100160410104ff67bbf7ef4852235f519ee2b3e17
Attribute 80 (Message-Authenticator) length=18
Value: cf5acc1af9f4dd509070c87d82d9e16a
Attribute 24 (State) length=18
Value: 161759b416165db0f3b4952e04b41a4d
STA 02:00:00:00:00:01: Received RADIUS packet matched with a pending request, round trip time 0.10 sec
RADIUS packet matching with station
decapsulated EAP packet (code=1 id=1 len=22) from RADIUS server: EAP-Request-MD5 (4)
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=1 method=4 vendor=0 vendorMethod=0
EAP: EAP entering state GET_METHOD
EAP: configuration does not allow: vendor 0 method 4
EAP: vendor 0 method 4 not allowed
CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=4 -> NAK
EAP: Status notification: refuse proposed method (param=MD5)
EAP: Building EAP-Nak (requested type 4 vendor=0 method=0 not allowed)
EAP: allowed methods - hexdump(len=1): 15
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
WPA: eapol_test_eapol_send(type=0 len=6)
TX EAP -> RADIUS - hexdump(len=6): 02 01 00 06 03 15
Encapsulating EAP message into a RADIUS packet
Copied RADIUS State Attribute
Sending RADIUS message to authentication server
RADIUS message: code=1 (Access-Request) identifier=1 length=152
Attribute 1 (User-Name) length=21
Value: 'eduroam at rnpteste.br'
Attribute 4 (NAS-IP-Address) length=6
Value: 127.0.0.1
Attribute 31 (Calling-Station-Id) length=19
Value: '02-00-00-00-00-01'
Attribute 12 (Framed-MTU) length=6
Value: 1400
Attribute 61 (NAS-Port-Type) length=6
Value: 19
Attribute 6 (Service-Type) length=6
Value: 2
Attribute 77 (Connect-Info) length=24
Value: 'CONNECT 11Mbps 802.11b'
Attribute 79 (EAP-Message) length=8
Value: 020100060315
Attribute 24 (State) length=18
Value: 161759b416165db0f3b4952e04b41a4d
Attribute 80 (Message-Authenticator) length=18
Value: f8039e5b4c04b57df13e32ca8b33427c
Next RADIUS client retransmit in 3 seconds
EAPOL: SUPP_BE entering state RECEIVE
Received 64 bytes from RADIUS server
Received RADIUS message
RADIUS message: code=11 (Access-Challenge) identifier=1 length=64
Attribute 79 (EAP-Message) length=8
Value: 010200061520
Attribute 80 (Message-Authenticator) length=18
Value: 2ec67f08f1d43987d71e57f05cb2ce8e
Attribute 24 (State) length=18
Value: 161759b417154cb0f3b4952e04b41a4d
STA 02:00:00:00:00:01: Received RADIUS packet matched with a pending request, round trip time 0.03 sec
RADIUS packet matching with station
decapsulated EAP packet (code=1 id=2 len=6) from RADIUS server: EAP-Request-TTLS (21)
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=2 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state GET_METHOD
CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=21
EAP: Status notification: accept proposed method (param=TTLS)
EAP: Initialize selected EAP method: vendor 0 method 21 (TTLS)
EAP-TTLS: Phase2 type: PAP
TLS: using phase1 config options
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected
EAP: EAP entering state METHOD
SSL: Received packet(len=6) - Flags 0x20
EAP-TTLS: Start (server ver=0, own ver=0)
SSL: (where=0x10 ret=0x1)
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:before/connect initialization
OpenSSL: TX ver=0x303 content_type=256 (TLS header info/)
OpenSSL: Message - hexdump(len=5): 16 03 01 01 28
OpenSSL: TX ver=0x303 content_type=22 (handshake/client hello)
OpenSSL: Message - hexdump(len=296): 01 00 01 24 03 03 d2 f5 ee a4 fd be 3d 97 82 7f 69 57 9c e6 62 56 22 8d 29 85 da fc c7 13 33 fe 57 a0 d6 2f e0 61 00 00 aa c0 30 c0 2c c0 28 c0 24 c0 14 c0 0a 00 a5 00 a3 00 a1 00 9f 00 6b 00 6a 00 69 00 68 00 39 00 38 00 37 00 36 00 88 00 87 00 86 00 85 c0 32 c0 2e c0 2a c0 26 c0 0f c0 05 00 9d 00 3d 00 35 00 84 c0 2f c0 2b c0 27 c0 23 c0 13 c0 09 00 a4 00 a2 00 a0 00 9e 00 67 00 40 00 3f 00 3e 00 33 00 32 00 31 00 30 00 9a 00 99 00 98 00 97 00 45 00 44 00 43 00 42 c0 31 c0 2d c0 29 c0 25 c0 0e c0 04 00 9c 00 3c 00 2f 00 96 00 41 c0 11 c0 07 c0 0c c0 02 00 05 00 04 c0 12 c0 08 00 16 00 13 00 10 00 0d c0 0d c0 03 00 0a 00 ff 01 00 00 51 00 0b 00 04 03 00 01 02 00 0a 00 1c 00 1a 00 17 00 19 00 1c 00 1b 00 18 00 1a 00 16 00 0e 00 0d 00 0b 00 0c 00 09 00 0a 00 0d 00 20 00 1e 06 01 06 02 06 03 05 01 05 02 05 03 04 01 04 02 04 03 03 01 03 02 03 03 02 01 02 02 02 03 00 0f 00 01 01
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv2/v3 write client hello A
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv2/v3 read server hello A
SSL: SSL_connect - want more data
SSL: 301 bytes pending from ssl_out
SSL: 301 bytes left to be sent out (of total 301 bytes)
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x10c5950
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
WPA: eapol_test_eapol_send(type=0 len=307)
TX EAP -> RADIUS - hexdump(len=307): 02 02 01 33 15 00 16 03 01 01 28 01 00 01 24 03 03 d2 f5 ee a4 fd be 3d 97 82 7f 69 57 9c e6 62 56 22 8d 29 85 da fc c7 13 33 fe 57 a0 d6 2f e0 61 00 00 aa c0 30 c0 2c c0 28 c0 24 c0 14 c0 0a 00 a5 00 a3 00 a1 00 9f 00 6b 00 6a 00 69 00 68 00 39 00 38 00 37 00 36 00 88 00 87 00 86 00 85 c0 32 c0 2e c0 2a c0 26 c0 0f c0 05 00 9d 00 3d 00 35 00 84 c0 2f c0 2b c0 27 c0 23 c0 13 c0 09 00 a4 00 a2 00 a0 00 9e 00 67 00 40 00 3f 00 3e 00 33 00 32 00 31 00 30 00 9a 00 99 00 98 00 97 00 45 00 44 00 43 00 42 c0 31 c0 2d c0 29 c0 25 c0 0e c0 04 00 9c 00 3c 00 2f 00 96 00 41 c0 11 c0 07 c0 0c c0 02 00 05 00 04 c0 12 c0 08 00 16 00 13 00 10 00 0d c0 0d c0 03 00 0a 00 ff 01 00 00 51 00 0b 00 04 03 00 01 02 00 0a 00 1c 00 1a 00 17 00 19 00 1c 00 1b 00 18 00 1a 00 16 00 0e 00 0d 00 0b 00 0c 00 09 00 0a 00 0d 00 20 00 1e 06 01 06 02 06 03 05 01 05 02 05 03 04 01 04 02 04 03 03 01 03 02 03 03 02 01 02 02 02 03 00 0f 00 01 01
Encapsulating EAP message into a RADIUS packet
Copied RADIUS State Attribute
Sending RADIUS message to authentication server
RADIUS message: code=1 (Access-Request) identifier=2 length=455
Attribute 1 (User-Name) length=21
Value: 'eduroam at rnpteste.br'
Attribute 4 (NAS-IP-Address) length=6
Value: 127.0.0.1
Attribute 31 (Calling-Station-Id) length=19
Value: '02-00-00-00-00-01'
Attribute 12 (Framed-MTU) length=6
Value: 1400
Attribute 61 (NAS-Port-Type) length=6
Value: 19
Attribute 6 (Service-Type) length=6
Value: 2
Attribute 77 (Connect-Info) length=24
Value: 'CONNECT 11Mbps 802.11b'
Attribute 79 (EAP-Message) length=255
Value: 0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc02bc027c023c013c00900a400a200a0009e00670040003f003e0033003200310030009a0099009800970045004400430042c031c02dc029c025c00ec004009c003c002f00960041c011c007c00cc00200050004c012c008001600130010000dc00dc003000a00ff01000051000b000403000102000a001c001a00170019001c001b0018001a00
Attribute 79 (EAP-Message) length=56
Value: 16000e000d000b000c0009000a000d0020001e060106020603050105020503040104020403030103020303020102020203000f000101
Attribute 24 (State) length=18
Value: 161759b417154cb0f3b4952e04b41a4d
Attribute 80 (Message-Authenticator) length=18
Value: 67ecbe0e885a25686f87da3397222a19
Next RADIUS client retransmit in 3 seconds
EAPOL: SUPP_BE entering state RECEIVE
EAPOL: startWhen --> 0
STA 02:00:00:00:00:01: Resending RADIUS message (id=2)
Next RADIUS client retransmit in 6 seconds
Received 20 bytes from RADIUS server
Received RADIUS message
RADIUS message: code=3 (Access-Reject) identifier=2 length=20
STA 02:00:00:00:00:01: Received RADIUS packet matched with a pending request, round trip time 2.10 sec
Allowing RADIUS Access-Reject without Message-Authenticator since it does not include EAP-Message
RADIUS packet matching with station
could not extract EAP-Message from RADIUS message
EAPOL: EAP key not available
EAPOL: EAP Session-Id not available
WPA: Clear old PMK and PTK
EAP: deinitialize previously used EAP method (21, TTLS) at EAP deinit
ENGINE: engine deinit
MPPE keys OK: 0 mismatch: 1
FAILURE
-------------- next part --------------
reading config from /etc/radsecproxy.conf
reading config file /etc/radsecproxy.conf
getgenericconfig: listenTLS = *:2083
getgenericconfig: SourceUDP = *:33000
getgenericconfig: ListenUDP = *:1830
getgenericconfig: SourceTLS = *:33001
getgenericconfig: LogLevel = 4
getgenericconfig: LogDestination = file:///var/log/radsecproxy.log
conftls_cb called for tls default
getgenericconfig: block tls default: CACertificateFile = /etc/freeradius/certs/radsec/ca.crt
getgenericconfig: block tls default: CertificateFile = /etc/freeradius/certs/radsec/federacao.crt
getgenericconfig: block tls default: CertificateKeyFile = /etc/freeradius/certs/radsec/federacao.key
tlsaddcacrl: updated TLS context default
tlscreatectx: created TLS context default
conftls_cb: added TLS block default
confclient_cb called for client localhost
getgenericconfig: block client localhost: host = localhost
getgenericconfig: block client localhost: type = udp
getgenericconfig: block client localhost: secret = eduroam
getgenericconfig: block client localhost: certificateNameCheck = off
resolvehostport: localhost -> ::1
confclient_cb called for client 200.131.219.102
getgenericconfig: block client 200.131.219.102: host = 200.131.219.102
getgenericconfig: block client 200.131.219.102: type = tls
getgenericconfig: block client 200.131.219.102: secret = radsec
getgenericconfig: block client 200.131.219.102: certificateNameCheck = off
resolvehostport: 200.131.219.102 -> 200.131.219.102
confclient_cb called for client homolog-idp.rnp.br
getgenericconfig: block client homolog-idp.rnp.br: host = homolog-idp.rnp.br
getgenericconfig: block client homolog-idp.rnp.br: type = tls
getgenericconfig: block client homolog-idp.rnp.br: secret = radsec
getgenericconfig: block client homolog-idp.rnp.br: certificateNameCheck = off
resolvehostport: homolog-idp.rnp.br -> 200.130.15.24
confclient_cb called for client 200.17.116.253
getgenericconfig: block client 200.17.116.253: host = 200.17.116.253
getgenericconfig: block client 200.17.116.253: type = tls
getgenericconfig: block client 200.17.116.253: secret = radsec
getgenericconfig: block client 200.17.116.253: certificateNameCheck = off
resolvehostport: 200.17.116.253 -> 200.17.116.253
confclient_cb called for client 200.130.15.22
getgenericconfig: block client 200.130.15.22: host = 200.130.15.22
getgenericconfig: block client 200.130.15.22: type = tls
getgenericconfig: block client 200.130.15.22: secret = radsec
getgenericconfig: block client 200.130.15.22: certificateNameCheck = off
resolvehostport: 200.130.15.22 -> 200.130.15.22
confclient_cb called for client homolog-tlr.rnp.br
getgenericconfig: block client homolog-tlr.rnp.br: host = homolog-tlr.rnp.br
getgenericconfig: block client homolog-tlr.rnp.br: type = udp
getgenericconfig: block client homolog-tlr.rnp.br: secret = eduroam
getgenericconfig: block client homolog-tlr.rnp.br: certificateNameCheck = off
resolvehostport: homolog-tlr.rnp.br -> 200.130.15.25
confclient_cb called for client eduroam.unipampa.edu.br
getgenericconfig: block client eduroam.unipampa.edu.br: host = eduroam.unipampa.edu.br
getgenericconfig: block client eduroam.unipampa.edu.br: type = tls
getgenericconfig: block client eduroam.unipampa.edu.br: secret = radsec
getgenericconfig: block client eduroam.unipampa.edu.br: certificateNameCheck = off
resolvehostport: eduroam.unipampa.edu.br -> 200.132.146.72
confserver_cb called for server 200.131.219.102
getgenericconfig: block server 200.131.219.102: host = 200.131.219.102
getgenericconfig: block server 200.131.219.102: type = tls
getgenericconfig: block server 200.131.219.102: secret = radsec
getgenericconfig: block server 200.131.219.102: certificateNameCheck = off
resolvehostport: 200.131.219.102 -> 200.131.219.102
confserver_cb called for server homolog-idp.rnp.br
getgenericconfig: block server homolog-idp.rnp.br: host = homolog-idp.rnp.br
getgenericconfig: block server homolog-idp.rnp.br: type = tls
getgenericconfig: block server homolog-idp.rnp.br: secret = radsec
getgenericconfig: block server homolog-idp.rnp.br: certificateNameCheck = off
resolvehostport: homolog-idp.rnp.br -> 200.130.15.24
confserver_cb called for server 200.17.116.253
getgenericconfig: block server 200.17.116.253: host = 200.17.116.253
getgenericconfig: block server 200.17.116.253: type = tls
getgenericconfig: block server 200.17.116.253: secret = radsec
getgenericconfig: block server 200.17.116.253: certificateNameCheck = off
resolvehostport: 200.17.116.253 -> 200.17.116.253
confserver_cb called for server 200.130.15.22
getgenericconfig: block server 200.130.15.22: host = 200.130.15.22
getgenericconfig: block server 200.130.15.22: type = tls
getgenericconfig: block server 200.130.15.22: secret = radsec
getgenericconfig: block server 200.130.15.22: certificateNameCheck = off
resolvehostport: 200.130.15.22 -> 200.130.15.22
confserver_cb called for server eduroam.unipampa.edu.br
getgenericconfig: block server eduroam.unipampa.edu.br: host = eduroam.unipampa.edu.br
getgenericconfig: block server eduroam.unipampa.edu.br: type = tls
getgenericconfig: block server eduroam.unipampa.edu.br: secret = radsec
getgenericconfig: block server eduroam.unipampa.edu.br: certificateNameCheck = off
resolvehostport: eduroam.unipampa.edu.br -> 200.132.146.72
confserver_cb called for server homolog-tlr.rnp.br
getgenericconfig: block server homolog-tlr.rnp.br: type = udp
getgenericconfig: block server homolog-tlr.rnp.br: secret = eduroam
getgenericconfig: block server homolog-tlr.rnp.br: certificateNameCheck = off
resolvehostport: homolog-tlr.rnp.br -> 200.130.15.25
confrealm_cb called for realm /@ufjfteste\.br$
getgenericconfig: block realm /@ufjfteste\.br$: server = 200.131.219.102
addsrvconfs: added server 200.131.219.102 for realm /@ufjfteste\.br$
addrealm: added realm /@ufjfteste\.br$
confrealm_cb called for realm /@rnpteste\.br$
getgenericconfig: block realm /@rnpteste\.br$: server = homolog-idp.rnp.br
addsrvconfs: added server homolog-idp.rnp.br for realm /@rnpteste\.br$
addrealm: added realm /@rnpteste\.br$
confrealm_cb called for realm /@pop-al\.br$
getgenericconfig: block realm /@pop-al\.br$: server = 200.17.116.253
addsrvconfs: added server 200.17.116.253 for realm /@pop-al\.br$
addrealm: added realm /@pop-al\.br$
confrealm_cb called for realm /@homolog-rnp\.br$
getgenericconfig: block realm /@homolog-rnp\.br$: server = 200.130.15.22
addsrvconfs: added server 200.130.15.22 for realm /@homolog-rnp\.br$
addrealm: added realm /@homolog-rnp\.br$
confrealm_cb called for realm /@unipampa\.edu\.br$
getgenericconfig: block realm /@unipampa\.edu\.br$: server = eduroam.unipampa.edu.br
addsrvconfs: added server eduroam.unipampa.edu.br for realm /@unipampa\.edu\.br$
addrealm: added realm /@unipampa\.edu\.br$
confrealm_cb called for realm *
getgenericconfig: block realm *: server = homolog-tlr.rnp.br
addrealm: constructed regexp .* from *
addsrvconfs: added server homolog-tlr.rnp.br for realm *
addrealm: added realm *
closing config file /etc/radsecproxy.conf
Jul 13 17:23:13 2017: radsecproxy revision 1.6.5 starting
Jul 13 17:23:13 2017: resolvehostport: (null) -> 0.0.0.0
Jul 13 17:23:13 2017: resolvehostport: (null) -> 0.0.0.0
Jul 13 17:23:13 2017: disable_DF_bit: disabling DF bit (Linux variant)
Jul 13 17:23:13 2017: resolvehostport: (null) -> 0.0.0.0
Jul 13 17:23:13 2017: disable_DF_bit: disabling DF bit (Linux variant)
Jul 13 17:23:13 2017: createlistener: listening for udp on *:1830
Jul 13 17:23:13 2017: resolvehostport: (null) -> 0.0.0.0
Jul 13 17:23:13 2017: createlistener: listening for tls on *:2083
Jul 13 17:23:13 2017: tlsconnect: called from clientwr
Jul 13 17:23:13 2017: connecttcphostlist: trying to open TCP connection to eduroam.unipampa.edu.br port 2083
Jul 13 17:23:13 2017: tlsconnect: called from clientwr
Jul 13 17:23:13 2017: connecttcphostlist: trying to open TCP connection to 200.130.15.22 port 2083
Jul 13 17:23:13 2017: udp server writer, waiting for signal
Jul 13 17:23:13 2017: tlsconnect: called from clientwr
Jul 13 17:23:13 2017: connecttcphostlist: trying to open TCP connection to 200.17.116.253 port 2083
Jul 13 17:23:13 2017: connecttcphostlist: TCP connection to 200.130.15.22 port 2083 up
Jul 13 17:23:13 2017: tlsconnect: called from clientwr
Jul 13 17:23:13 2017: connecttcphostlist: trying to open TCP connection to homolog-idp.rnp.br port 2083
Jul 13 17:23:13 2017: tlsconnect: called from clientwr
Jul 13 17:23:13 2017: connecttcphostlist: trying to open TCP connection to 200.131.219.102 port 2083
Jul 13 17:23:13 2017: connecttoserver: connect failed
Jul 13 17:23:13 2017: connecttcphostlist: failed
Jul 13 17:23:13 2017: tlsconnect: TLS connection to 200.130.15.22 up
Jul 13 17:23:13 2017: connecttcphostlist: TCP connection to 200.131.219.102 port 2083 up
Jul 13 17:23:13 2017: connecttcphostlist: TCP connection to eduroam.unipampa.edu.br port 2083 up
Jul 13 17:23:13 2017: tlsconnect: TLS connection to 200.131.219.102 up
Jul 13 17:23:14 2017: tlsconnect: TLS connection to eduroam.unipampa.edu.br up
Jul 13 17:23:15 2017: connecttcphostlist: trying to open TCP connection to homolog-idp.rnp.br port 2083
Jul 13 17:23:15 2017: connecttcphostlist: TCP connection to homolog-idp.rnp.br port 2083 up
Jul 13 17:23:15 2017: tlsconnect: TLS connection to homolog-idp.rnp.br up
Jul 13 17:23:36 2017: tlsservernew: incoming TLS connection from 200.131.219.102
Jul 13 17:23:36 2017: tlsserverrd: starting for 200.131.219.102
Jul 13 17:23:36 2017: tlsserverwr: starting for 200.131.219.102
Jul 13 17:23:36 2017: tlsserverwr: waiting for signal
Jul 13 17:23:36 2017: radtlsget: got 161 bytes
Jul 13 17:23:36 2017: tlsserverrd: got Radius message from 200.131.219.102
Jul 13 17:23:36 2017: buf2radmsg: message auth ok
Jul 13 17:23:36 2017: radsrv: code 1, id 50
Jul 13 17:23:36 2017: Access-Request with username: eduroam at rnpteste.br
Jul 13 17:23:36 2017: found matching realm: /@rnpteste\.br$
Jul 13 17:23:36 2017: found matching conf: homolog-idp.rnp.br
Jul 13 17:23:36 2017: sendrq: inserting packet with id 0 in queue for homolog-idp.rnp.br
Jul 13 17:23:36 2017: sendrq: signalling client writer
Jul 13 17:23:36 2017: freerealm: called with refcount 3
Jul 13 17:23:36 2017: clientwr: got new request
Jul 13 17:23:36 2017: clientradputtls: Sent 161 bytes, Radius packet of length 161 to TLS peer homolog-idp.rnp.br
Jul 13 17:23:36 2017: radtlsget: got 83 bytes
Jul 13 17:23:36 2017: buf2radmsg: message auth ok
Jul 13 17:23:36 2017: got Access-Challenge message with id 0
Jul 13 17:23:36 2017: replyh: passing Access-Challenge to client 200.131.219.102 (200.131.219.102)
Jul 13 17:23:36 2017: signalling server writer
Jul 13 17:23:36 2017: freerq: called with refcount 3
Jul 13 17:23:36 2017: tlsserverwr: got signal
Jul 13 17:23:36 2017: tlsserverwr: sent 83 bytes, Radius packet of length 83 to 200.131.219.102
Jul 13 17:23:36 2017: freerq: called with refcount 2
Jul 13 17:23:36 2017: tlsserverwr: waiting for signal
Jul 13 17:23:37 2017: radtlsget: got 161 bytes
Jul 13 17:23:37 2017: tlsserverrd: got Radius message from 200.131.219.102
Jul 13 17:23:37 2017: buf2radmsg: message auth ok
Jul 13 17:23:37 2017: radsrv: code 1, id 140
Jul 13 17:23:37 2017: Access-Request with username: eduroam at rnpteste.br
Jul 13 17:23:37 2017: found matching realm: /@rnpteste\.br$
Jul 13 17:23:37 2017: found matching conf: homolog-idp.rnp.br
Jul 13 17:23:37 2017: sendrq: inserting packet with id 1 in queue for homolog-idp.rnp.br
Jul 13 17:23:37 2017: sendrq: signalling client writer
Jul 13 17:23:37 2017: freerealm: called with refcount 3
Jul 13 17:23:37 2017: clientwr: got new request
Jul 13 17:23:37 2017: clientradputtls: Sent 161 bytes, Radius packet of length 161 to TLS peer homolog-idp.rnp.br
Jul 13 17:23:37 2017: radtlsget: got 67 bytes
Jul 13 17:23:37 2017: buf2radmsg: message auth ok
Jul 13 17:23:37 2017: got Access-Challenge message with id 1
Jul 13 17:23:37 2017: replyh: passing Access-Challenge to client 200.131.219.102 (200.131.219.102)
Jul 13 17:23:37 2017: signalling server writer
Jul 13 17:23:37 2017: freerq: called with refcount 3
Jul 13 17:23:37 2017: tlsserverwr: got signal
Jul 13 17:23:37 2017: tlsserverwr: sent 67 bytes, Radius packet of length 67 to 200.131.219.102
Jul 13 17:23:37 2017: freerq: called with refcount 2
Jul 13 17:23:37 2017: tlsserverwr: waiting for signal
Jul 13 17:23:37 2017: radtlsget: got 464 bytes
Jul 13 17:23:37 2017: tlsserverrd: got Radius message from 200.131.219.102
Jul 13 17:23:37 2017: buf2radmsg: message auth ok
Jul 13 17:23:37 2017: radsrv: code 1, id 27
Jul 13 17:23:37 2017: Access-Request with username: eduroam at rnpteste.br
Jul 13 17:23:37 2017: found matching realm: /@rnpteste\.br$
Jul 13 17:23:37 2017: found matching conf: homolog-idp.rnp.br
Jul 13 17:23:37 2017: sendrq: inserting packet with id 2 in queue for homolog-idp.rnp.br
Jul 13 17:23:37 2017: sendrq: signalling client writer
Jul 13 17:23:37 2017: freerealm: called with refcount 3
Jul 13 17:23:37 2017: clientwr: got new request
Jul 13 17:23:37 2017: clientradputtls: Sent 464 bytes, Radius packet of length 464 to TLS peer homolog-idp.rnp.br
Jul 13 17:23:37 2017: radtlsget: got 1071 bytes
Jul 13 17:23:37 2017: buf2radmsg: message auth ok
Jul 13 17:23:37 2017: got Access-Challenge message with id 2
Jul 13 17:23:37 2017: replyh: passing Access-Challenge to client 200.131.219.102 (200.131.219.102)
Jul 13 17:23:37 2017: signalling server writer
Jul 13 17:23:37 2017: freerq: called with refcount 3
Jul 13 17:23:37 2017: tlsserverwr: got signal
Jul 13 17:23:37 2017: tlsserverwr: sent 1071 bytes, Radius packet of length 1071 to 200.131.219.102
Jul 13 17:23:37 2017: freerq: called with refcount 2
Jul 13 17:23:37 2017: tlsserverwr: waiting for signal
Jul 13 17:23:37 2017: radtlsget: connection lost
Jul 13 17:23:37 2017: tlsserverrd: connection from 200.131.219.102 lost
Jul 13 17:23:37 2017: tlsserverrd: waiting for writer to end
Jul 13 17:23:37 2017: tlsserverwr: got signal
Jul 13 17:23:37 2017: tlsserverwr: exiting as requested
Jul 13 17:23:37 2017: tlsserverrd: reader for 200.131.219.102 exiting
Jul 13 17:23:37 2017: freerq: called with refcount 1
Jul 13 17:23:37 2017: freerq: called with refcount 1
Jul 13 17:23:37 2017: freerq: called with refcount 1
Jul 13 17:23:40 2017: tlsservernew: incoming TLS connection from 200.131.219.102
Jul 13 17:23:40 2017: tlsserverrd: starting for 200.131.219.102
Jul 13 17:23:40 2017: tlsserverwr: starting for 200.131.219.102
Jul 13 17:23:40 2017: tlsserverwr: waiting for signal
Jul 13 17:23:40 2017: radtlsget: got 464 bytes
Jul 13 17:23:40 2017: tlsserverrd: got Radius message from 200.131.219.102
Jul 13 17:23:40 2017: buf2radmsg: message auth ok
Jul 13 17:23:40 2017: radsrv: code 1, id 1
Jul 13 17:23:40 2017: Access-Request with username: eduroam at rnpteste.br
Jul 13 17:23:40 2017: found matching realm: /@rnpteste\.br$
Jul 13 17:23:40 2017: found matching conf: homolog-idp.rnp.br
Jul 13 17:23:40 2017: sendrq: inserting packet with id 3 in queue for homolog-idp.rnp.br
Jul 13 17:23:40 2017: sendrq: signalling client writer
Jul 13 17:23:40 2017: freerealm: called with refcount 3
Jul 13 17:23:40 2017: clientwr: got new request
Jul 13 17:23:40 2017: clientradputtls: Sent 464 bytes, Radius packet of length 464 to TLS peer homolog-idp.rnp.br
Jul 13 17:23:41 2017: radtlsget: got 23 bytes
Jul 13 17:23:41 2017: got Access-Reject message with id 3
Jul 13 17:23:41 2017: Access-Reject for user eduroam at rnpteste.br stationid 02-00-00-00-00-01 from homolog-idp.rnp.br to 200.131.219.102 (200.131.219.102)
Jul 13 17:23:41 2017: replyh: passing Access-Reject to client 200.131.219.102 (200.131.219.102)
Jul 13 17:23:41 2017: signalling server writer
Jul 13 17:23:41 2017: freerq: called with refcount 3
Jul 13 17:23:41 2017: tlsserverwr: got signal
Jul 13 17:23:41 2017: tlsserverwr: sent 23 bytes, Radius packet of length 23 to 200.131.219.102
Jul 13 17:23:41 2017: freerq: called with refcount 2
Jul 13 17:23:41 2017: tlsserverwr: waiting for signal
Jul 13 17:23:43 2017: radtlsget: connection lost
Jul 13 17:23:43 2017: tlsconnect: called from tlsclientrd
Jul 13 17:23:43 2017: radtlsget: connection lost
Jul 13 17:23:43 2017: tlsconnect: called from tlsclientrd
Jul 13 17:23:43 2017: radtlsget: connection lost
Jul 13 17:23:43 2017: tlsconnect: called from tlsclientrd
Jul 13 17:23:43 2017: connecttoserver: connect failed
Jul 13 17:23:43 2017: connecttcphostlist: failed
Jul 13 17:23:43 2017: tlsconnect: sleeping 30s
Jul 13 17:23:45 2017: connecttcphostlist: trying to open TCP connection to 200.131.219.102 port 2083
Jul 13 17:23:45 2017: connecttoserver: connect failed
Jul 13 17:23:45 2017: connecttcphostlist: failed
Jul 13 17:23:45 2017: tlsconnect: sleeping 32s
Jul 13 17:23:45 2017: connecttcphostlist: trying to open TCP connection to 200.130.15.22 port 2083
Jul 13 17:23:45 2017: connecttoserver: connect failed
Jul 13 17:23:45 2017: connecttcphostlist: failed
Jul 13 17:23:45 2017: tlsconnect: sleeping 32s
Jul 13 17:23:45 2017: connecttcphostlist: trying to open TCP connection to eduroam.unipampa.edu.br port 2083
Jul 13 17:23:45 2017: connecttoserver: connect failed
Jul 13 17:23:45 2017: connecttcphostlist: failed
Jul 13 17:23:45 2017: tlsconnect: sleeping 31s
Jul 13 17:23:46 2017: radtlsget: connection lost
Jul 13 17:23:46 2017: tlsserverrd: connection from 200.131.219.102 lost
Jul 13 17:23:46 2017: tlsserverrd: waiting for writer to end
Jul 13 17:23:46 2017: tlsserverwr: got signal
Jul 13 17:23:46 2017: tlsserverwr: exiting as requested
Jul 13 17:23:46 2017: tlsserverrd: reader for 200.131.219.102 exiting
Jul 13 17:23:46 2017: freerq: called with refcount 1
Jul 13 17:23:47 2017: radtlsget: connection lost
Jul 13 17:23:47 2017: tlsconnect: called from tlsclientrd
Jul 13 17:23:49 2017: connecttcphostlist: trying to open TCP connection to homolog-idp.rnp.br port 2083
Jul 13 17:23:49 2017: connecttoserver: connect failed
Jul 13 17:23:49 2017: connecttcphostlist: failed
Jul 13 17:23:49 2017: tlsconnect: sleeping 34s
-------------- next part --------------
FreeRADIUS Version 3.0.12
Copyright (C) 1999-2016 The FreeRADIUS server project and contributors
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
Ignoring old-style configuration entry "secret" in realm "~(.*\.)*rnpteste\.br$"
Debugger not attached
Creating attribute Unix-Group
Creating attribute LDAP-Group
tls: Using cached TLS configuration from previous invocation
tls: Using cached TLS configuration from previous invocation
[/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT".
[/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT".
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
rlm_mschap (mschap): using internal authentication
rlm_ldap: libldap vendor: OpenLDAP, version: 20442
rlm_ldap (ldap): Initialising connection pool
rlm_ldap (ldap): Opening additional connection (0), 1 of 32 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (1), 1 of 31 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (2), 1 of 30 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (3), 1 of 29 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (4), 1 of 28 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
Ignoring "sql" (see raddb/mods-available/README.rst)
radiusd: #### Opening IP addresses and Ports ####
Listening on auth proto tcp address * port 2083 (TLS) bound to server default
Listening on auth proto tcp address :: port 2083 (TLS)
Listening on auth address 127.0.0.1 port 4000
Listening on auth address * port 1812 bound to server default
Listening on acct address * port 1813 bound to server default
Listening on auth address :: port 1812 bound to server default
Listening on acct address :: port 1813 bound to server default
Listening on auth address * port 18120 bound to server inner-tunnel
Listening on proxy address * port 36116
Listening on proxy address :: port 46813
Ready to process requests
Listening on auth from client (200.130.15.23, 33001) -> (*, 2083, virtual-server=default)
Waking up in 0.1 seconds.
Waking up in 0.1 seconds.
Waking up in 0.1 seconds.
Waking up in 29.4 seconds.
(0) Application data status 7
(0) tls_recv: Access-Request packet from host 200.130.15.23 port 33001, id=0, length=161
(0) Received Access-Request Id 0 from 200.130.15.23:33001 to 0.0.0.0:2083 length 161
(0) User-Name = "eduroam at rnpteste.br"
(0) NAS-IP-Address = 127.0.0.1
(0) Calling-Station-Id = "02-00-00-00-00-01"
(0) Framed-MTU = 1400
(0) NAS-Port-Type = Wireless-802.11
(0) Service-Type = Framed-User
(0) Connect-Info = "CONNECT 11Mbps 802.11b"
(0) EAP-Message = 0x0200001801656475726f616d40726e7074657374652e6272
(0) Message-Authenticator = 0x3eae28718e7454d14f37816adabd4878
(0) Event-Timestamp = "Jul 13 2017 17:23:36 BRT"
(0) Proxy-State = 0x30
(0) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(0) # Executing group from file /etc/freeradius/sites-enabled/default
(0) eap: EAP session adding &reply:State = 0x161759b416165db0
(0) # Executing group from file /etc/freeradius/sites-enabled/default
(0) Sent Access-Challenge Id 0 from 0.0.0.0:2083 to 200.130.15.23:33001 length 0
(0) EAP-Message = 0x010100160410104ff67bbf7ef4852235f519ee2b3e17
(0) Message-Authenticator = 0x00000000000000000000000000000000
(0) State = 0x161759b416165db0f3b4952e04b41a4d
(0) Proxy-State = 0x30
Waking up in 0.3 seconds.
(0) Application data status 7
(0) tls_recv: Access-Request packet from host 200.130.15.23 port 33001, id=1, length=161
(1) Received Access-Request Id 1 from 200.130.15.23:33001 to 0.0.0.0:2083 length 161
(1) User-Name = "eduroam at rnpteste.br"
(1) NAS-IP-Address = 127.0.0.1
(1) Calling-Station-Id = "02-00-00-00-00-01"
(1) Framed-MTU = 1400
(1) NAS-Port-Type = Wireless-802.11
(1) Service-Type = Framed-User
(1) Connect-Info = "CONNECT 11Mbps 802.11b"
(1) EAP-Message = 0x020100060315
(1) State = 0x161759b416165db0f3b4952e04b41a4d
(1) Message-Authenticator = 0x03c7cdfd254a26072eaf6d48c8bdc3a6
(1) Event-Timestamp = "Jul 13 2017 17:23:36 BRT"
(1) Proxy-State = 0x31
(1) # Executing section authorize from file /etc/freeradius/sites-enabled/default
rlm_ldap (ldap): Reserved connection (0)
(1) ldap: Performing search in "dc=eduroam,dc=across" with filter "(uid=eduroam at rnpteste.br)", scope "sub"
(1) ldap: Waiting for search result...
Waking up in 0.3 seconds.
(1) ldap: Search returned no results
rlm_ldap (ldap): Released connection (0)
rlm_ldap (ldap): Need 5 more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (5), 1 of 27 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
(1) pap: WARNING: No "known good" password found for the user. Not setting Auth-Type
(1) pap: WARNING: Authentication will fail unless a "known good" password is available
(1) # Executing group from file /etc/freeradius/sites-enabled/default
(1) eap: Expiring EAP session with state 0x161759b416165db0
(1) eap: Finished EAP session with state 0x161759b416165db0
(1) eap: Previous EAP request found for state 0x161759b416165db0, released from the list
(1) eap: Found mutually acceptable type TTLS (21)
(1) eap: EAP session adding &reply:State = 0x161759b417154cb0
(1) # Executing group from file /etc/freeradius/sites-enabled/default
(1) Sent Access-Challenge Id 1 from 0.0.0.0:2083 to 200.130.15.23:33001 length 0
(1) EAP-Message = 0x010200061520
(1) Message-Authenticator = 0x00000000000000000000000000000000
(1) State = 0x161759b417154cb0f3b4952e04b41a4d
(1) Proxy-State = 0x31
(0) Application data status 7
(0) tls_recv: Access-Request packet from host 200.130.15.23 port 33001, id=2, length=464
(2) Received Access-Request Id 2 from 200.130.15.23:33001 to 0.0.0.0:2083 length 464
(2) User-Name = "eduroam at rnpteste.br"
(2) NAS-IP-Address = 127.0.0.1
(2) Calling-Station-Id = "02-00-00-00-00-01"
(2) Framed-MTU = 1400
(2) NAS-Port-Type = Wireless-802.11
(2) Service-Type = Framed-User
(2) Connect-Info = "CONNECT 11Mbps 802.11b"
(2) EAP-Message = 0x0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc0
(2) State = 0x161759b417154cb0f3b4952e04b41a4d
(2) Message-Authenticator = 0x6b32fe02a4f59cfaed271d8228aef6fa
(2) Event-Timestamp = "Jul 13 2017 17:23:37 BRT"
(2) Proxy-State = 0x32
(2) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(2) # Executing group from file /etc/freeradius/sites-enabled/default
(2) eap: Expiring EAP session with state 0x161759b417154cb0
(2) eap: Finished EAP session with state 0x161759b417154cb0
(2) eap: Previous EAP request found for state 0x161759b417154cb0, released from the list
(2) eap: EAP session adding &reply:State = 0x161759b414144cb0
(2) # Executing group from file /etc/freeradius/sites-enabled/default
(2) Sent Access-Challenge Id 2 from 0.0.0.0:2083 to 200.130.15.23:33001 length 0
(2) EAP-Message = 0x010303ec15c000000a96160303005e0200005a03035abb37296a95058a948ba3bddc38590e887f725d4ac8bd7bff479322ca926c85205b51bfdcc1a455f10894c0146589ba2cd9b3ea9dd4e663291e53621985c79168c030000012ff01000100000b000403000102000f00010116030308d30b0008cf00
(2) Message-Authenticator = 0x00000000000000000000000000000000
(2) State = 0x161759b414144cb0f3b4952e04b41a4d
(2) Proxy-State = 0x32
Waking up in 0.2 seconds.
Waking up in 4.6 seconds.
(0) Application data status 7
(0) tls_recv: Access-Request packet from host 200.130.15.23 port 33001, id=3, length=464
(3) Received Access-Request Id 3 from 200.130.15.23:33001 to 0.0.0.0:2083 length 464
(3) User-Name = "eduroam at rnpteste.br"
(3) NAS-IP-Address = 127.0.0.1
(3) Calling-Station-Id = "02-00-00-00-00-01"
(3) Framed-MTU = 1400
(3) NAS-Port-Type = Wireless-802.11
(3) Service-Type = Framed-User
(3) Connect-Info = "CONNECT 11Mbps 802.11b"
(3) EAP-Message = 0x0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc0
(3) State = 0x161759b417154cb0f3b4952e04b41a4d
(3) Message-Authenticator = 0x384c2741f7321ca2d8e8f78b9c0864b3
(3) Event-Timestamp = "Jul 13 2017 17:23:37 BRT"
(3) Proxy-State = 0x32
(3) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(3) # Executing group from file /etc/freeradius/sites-enabled/default
(3) eap: Expiring EAP session with state 0x161759b414144cb0
rlm_eap (EAP): No EAP session matching state 0x161759b417154cb0
(3) eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request
(3) # Executing group from file /etc/freeradius/sites-enabled/default
(3) eap: Expiring EAP session with state 0x161759b414144cb0
rlm_eap (EAP): No EAP session matching state 0x161759b417154cb0
(3) eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request
Waking up in 0.3 seconds.
Waking up in 0.6 seconds.
(3) Sent Access-Reject Id 3 from 0.0.0.0:2083 to 200.130.15.23:33001 length 23
(3) Proxy-State = 0x32
Waking up in 0.8 seconds.
Waking up in 3.0 seconds.
Waking up in 0.3 seconds.
Waking up in 24.9 seconds.
-------------- next part --------------
FreeRADIUS Version 3.0.12
Copyright (C) 1999-2016 The FreeRADIUS server project and contributors
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
/etc/freeradius/proxy.conf[35]: Ignoring duplicate configuration item 'ipaddr'
Ignoring old-style configuration entry "secret" in realm "~(.*\.)*ufjfteste\.br$"
Debugger not attached
Creating attribute LDAP-Group
Creating attribute Unix-Group
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
rlm_mschap (mschap): using internal authentication
[/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT".
[/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT".
rlm_ldap: libldap vendor: OpenLDAP, version: 20442
rlm_ldap (ldap): Initialising connection pool
rlm_ldap (ldap): Opening additional connection (0), 1 of 32 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (1), 1 of 31 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (2), 1 of 30 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (3), 1 of 29 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (4), 1 of 28 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
tls: Using cached TLS configuration from previous invocation
tls: Using cached TLS configuration from previous invocation
Ignoring "sql" (see raddb/mods-available/README.rst)
radiusd: #### Opening IP addresses and Ports ####
Listening on auth proto tcp address * port 2083 (TLS) bound to server default
Listening on auth proto tcp address :: port 2083 (TLS)
Listening on auth address 127.0.0.1 port 4000
Listening on auth address * port 18120 bound to server inner-tunnel
Listening on auth address * port 1812 bound to server default
Listening on acct address * port 1813 bound to server default
Listening on auth address :: port 1812 bound to server default
Listening on acct address :: port 1813 bound to server default
Listening on proxy address * port 35952
Listening on proxy address :: port 32926
Ready to process requests
Listening on auth from client (200.130.15.23, 33001) -> (*, 2083, virtual-server=default)
Waking up in 0.1 seconds.
Waking up in 0.1 seconds.
Waking up in 29.4 seconds.
Waking up in 0.3 seconds.
(0) Received Access-Request Id 0 from 127.0.0.1:49487 to 127.0.0.1:1812 length 152
(0) User-Name = "eduroam at rnpteste.br"
(0) NAS-IP-Address = 127.0.0.1
(0) Calling-Station-Id = "02-00-00-00-00-01"
(0) Framed-MTU = 1400
(0) NAS-Port-Type = Wireless-802.11
(0) Service-Type = Framed-User
(0) Connect-Info = "CONNECT 11Mbps 802.11b"
(0) EAP-Message = 0x0200001801656475726f616d40726e7074657374652e6272
(0) Message-Authenticator = 0x425dab3569ba0abc75b3ed0250beb9bd
(0) # Executing section authorize from file /etc/freeradius/sites-enabled/default
rlm_ldap (ldap): Reserved connection (0)
(0) ldap: Performing search in "dc=eduroam,dc=across" with filter "(uid=eduroam at rnpteste.br)", scope "sub"
(0) ldap: Waiting for search result...
(0) ldap: Search returned no results
rlm_ldap (ldap): Released connection (0)
rlm_ldap (ldap): Need 5 more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (5), 1 of 27 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
Trying SSL to port 2083
(0) Sent Access-Request Id 50 from 200.131.219.102:53625 to 200.130.15.23:2083 length 161
Listening on proxy (200.131.219.102, 53625) -> home_server (200.130.15.23, 2083)
(0) User-Name = "eduroam at rnpteste.br"
Waking up in 0.2 seconds.
(0) NAS-IP-Address = 127.0.0.1
(0) Calling-Station-Id = "02-00-00-00-00-01"
(0) Framed-MTU = 1400
(0) NAS-Port-Type = Wireless-802.11
(0) Service-Type = Framed-User
(0) Connect-Info = "CONNECT 11Mbps 802.11b"
(0) EAP-Message = 0x0200001801656475726f616d40726e7074657374652e6272
(0) Message-Authenticator = 0x425dab3569ba0abc75b3ed0250beb9bd
(0) Event-Timestamp = "Jul 13 2017 17:23:36 BRT"
(0) Proxy-State = 0x30
(0) Marking home server 200.130.15.23 port 2083 alive
Waking up in 0.3 seconds.
(0) Received Access-Challenge Id 50 from 200.130.15.23:2083 to 200.131.219.102:53625 length 83
(0) EAP-Message = 0x010100160410104ff67bbf7ef4852235f519ee2b3e17
(0) Message-Authenticator = 0x3ef1382a40d8a8d53a382574129aca6b
(0) State = 0x161759b416165db0f3b4952e04b41a4d
(0) Proxy-State = 0x30
(0) # Executing section post-proxy from file /etc/freeradius/sites-enabled/default
(0) # Executing group from file /etc/freeradius/sites-enabled/default
(0) Sent Access-Challenge Id 0 from 127.0.0.1:1812 to 127.0.0.1:49487 length 0
(0) EAP-Message = 0x010100160410104ff67bbf7ef4852235f519ee2b3e17
(0) Message-Authenticator = 0x3ef1382a40d8a8d53a382574129aca6b
(0) State = 0x161759b416165db0f3b4952e04b41a4d
Waking up in 0.3 seconds.
(1) Received Access-Request Id 1 from 127.0.0.1:49487 to 127.0.0.1:1812 length 152
(1) User-Name = "eduroam at rnpteste.br"
(1) NAS-IP-Address = 127.0.0.1
(1) Calling-Station-Id = "02-00-00-00-00-01"
(1) Framed-MTU = 1400
(1) NAS-Port-Type = Wireless-802.11
(1) Service-Type = Framed-User
(1) Connect-Info = "CONNECT 11Mbps 802.11b"
(1) EAP-Message = 0x020100060315
(1) State = 0x161759b416165db0f3b4952e04b41a4d
(1) Message-Authenticator = 0xf8039e5b4c04b57df13e32ca8b33427c
(1) # Executing section authorize from file /etc/freeradius/sites-enabled/default
rlm_ldap (ldap): Reserved connection (1)
(1) ldap: Performing search in "dc=eduroam,dc=across" with filter "(uid=eduroam at rnpteste.br)", scope "sub"
(1) ldap: Waiting for search result...
(1) ldap: Search returned no results
rlm_ldap (ldap): Released connection (1)
(1) Sent Access-Request Id 140 from 200.131.219.102:53625 to 200.130.15.23:2083 length 161
(1) User-Name = "eduroam at rnpteste.br"
(1) NAS-IP-Address = 127.0.0.1
(1) Calling-Station-Id = "02-00-00-00-00-01"
(1) Framed-MTU = 1400
(1) NAS-Port-Type = Wireless-802.11
(1) Service-Type = Framed-User
(1) Connect-Info = "CONNECT 11Mbps 802.11b"
(1) EAP-Message = 0x020100060315
(1) State = 0x161759b416165db0f3b4952e04b41a4d
(1) Message-Authenticator = 0xf8039e5b4c04b57df13e32ca8b33427c
(1) Event-Timestamp = "Jul 13 2017 17:23:36 BRT"
(1) Proxy-State = 0x31
Waking up in 0.3 seconds.
(1) Received Access-Challenge Id 140 from 200.130.15.23:2083 to 200.131.219.102:53625 length 67
(1) EAP-Message = 0x010200061520
(1) Message-Authenticator = 0x86c5fd310377237b9e6bff86b0a425f1
(1) State = 0x161759b417154cb0f3b4952e04b41a4d
(1) Proxy-State = 0x31
(1) # Executing section post-proxy from file /etc/freeradius/sites-enabled/default
(1) # Executing group from file /etc/freeradius/sites-enabled/default
(1) Sent Access-Challenge Id 1 from 127.0.0.1:1812 to 127.0.0.1:49487 length 0
(1) EAP-Message = 0x010200061520
(1) Message-Authenticator = 0x86c5fd310377237b9e6bff86b0a425f1
(1) State = 0x161759b417154cb0f3b4952e04b41a4d
Waking up in 0.3 seconds.
(2) Received Access-Request Id 2 from 127.0.0.1:49487 to 127.0.0.1:1812 length 455
(2) User-Name = "eduroam at rnpteste.br"
(2) NAS-IP-Address = 127.0.0.1
(2) Calling-Station-Id = "02-00-00-00-00-01"
(2) Framed-MTU = 1400
(2) NAS-Port-Type = Wireless-802.11
(2) Service-Type = Framed-User
(2) Connect-Info = "CONNECT 11Mbps 802.11b"
(2) EAP-Message = 0x0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc0
(2) State = 0x161759b417154cb0f3b4952e04b41a4d
(2) Message-Authenticator = 0x67ecbe0e885a25686f87da3397222a19
(2) # Executing section authorize from file /etc/freeradius/sites-enabled/default
rlm_ldap (ldap): Reserved connection (2)
(2) ldap: Performing search in "dc=eduroam,dc=across" with filter "(uid=eduroam at rnpteste.br)", scope "sub"
(2) ldap: Waiting for search result...
(2) ldap: Search returned no results
rlm_ldap (ldap): Released connection (2)
rlm_ldap (ldap): Need 4 more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (6), 1 of 26 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Bind successful
(2) Sent Access-Request Id 27 from 200.131.219.102:53625 to 200.130.15.23:2083 length 464
(2) User-Name = "eduroam at rnpteste.br"
(2) NAS-IP-Address = 127.0.0.1
(2) Calling-Station-Id = "02-00-00-00-00-01"
(2) Framed-MTU = 1400
(2) NAS-Port-Type = Wireless-802.11
(2) Service-Type = Framed-User
(2) Connect-Info = "CONNECT 11Mbps 802.11b"
(2) EAP-Message = 0x0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc0
(2) State = 0x161759b417154cb0f3b4952e04b41a4d
(2) Message-Authenticator = 0x67ecbe0e885a25686f87da3397222a19
(2) Event-Timestamp = "Jul 13 2017 17:23:37 BRT"
(2) Proxy-State = 0x32
Received packet will be too large! Set "fragment_size = 1071"
Closing TLS socket to home server
Client has closed connection
(2) Waiting for client retransmission in order to do a proxy retransmit
Waking up in 0.1 seconds.
Waking up in 4.6 seconds.
Trying SSL to port 2083
Listening on proxy (200.131.219.102, 57052) -> home_server (200.130.15.23, 2083)
(2) Sent Access-Request Id 1 from 200.131.219.102:57052 to 200.130.15.23:2083 length 464
(2) User-Name = "eduroam at rnpteste.br"
(2) NAS-IP-Address = 127.0.0.1
(2) Calling-Station-Id = "02-00-00-00-00-01"
(2) Framed-MTU = 1400
(2) NAS-Port-Type = Wireless-802.11
(2) Service-Type = Framed-User
(2) Connect-Info = "CONNECT 11Mbps 802.11b"
(2) EAP-Message = 0x0202013315001603010128010001240303d2f5eea4fdbe3d97827f69579ce66256228d2985dafcc71333fe57a0d62fe0610000aac030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc0
(2) State = 0x161759b417154cb0f3b4952e04b41a4d
(2) Message-Authenticator = 0x67ecbe0e885a25686f87da3397222a19
(2) Event-Timestamp = "Jul 13 2017 17:23:37 BRT"
(2) Proxy-State = 0x32
Waking up in 1.8 seconds.
Waking up in 0.3 seconds.
(2) Received Access-Reject Id 1 from 200.130.15.23:2083 to 200.131.219.102:57052 length 23
(2) Proxy-State = 0x32
(2) # Executing section post-proxy from file /etc/freeradius/sites-enabled/default
(2) # Executing group from file /etc/freeradius/sites-enabled/default
rlm_eap (EAP): No EAP session matching state 0x161759b417154cb0
(2) eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request
Waking up in 0.5 seconds.
Waking up in 0.1 seconds.
(2) Sent Access-Reject Id 2 from 127.0.0.1:1812 to 127.0.0.1:49487 length 20
Waking up in 1.3 seconds.
Reached idle timeout on socket auth from client (200.130.15.23, 33001) -> (*, 2083, virtual-server=default)
... shutting down socket auth from client (200.130.15.23, 33001) -> (*, 2083, virtual-server=default)
Waking up in 2.6 seconds.
More information about the Freeradius-Users
mailing list