AVP EAP-KEY name support in FR

Srinu Bandari sbandari at vitesse.com
Wed Feb 20 05:51:52 CET 2013


Alan,

We had tried with latest build, now it sends Access-Challenge and there is a segmentation fault.

Please find debug log for the latest ones as below.


Sun Aug 19 02:26:20 2012 : Info: radiusd: FreeRADIUS Version 2.2.1, for host x86_64-unknown-linux-gnu, built on Feb 19 2013 at 01:22:31
Sun Aug 19 02:26:20 2012 : Debug: Server was built with:
Sun Aug 19 02:26:20 2012 : Debug:   accounting
Sun Aug 19 02:26:20 2012 : Debug:   authentication
Sun Aug 19 02:26:20 2012 : Debug:  WITH_DHCP
Sun Aug 19 02:26:20 2012 : Debug:  WITH_VMPS
Sun Aug 19 02:26:20 2012 : Debug: Server core libs:
.
.
.
Sun Aug 19 02:26:20 2012 : Debug: Listening on authentication address * port 1812
Sun Aug 19 02:26:20 2012 : Debug: Listening on accounting address * port 1813
Sun Aug 19 02:26:20 2012 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock
Sun Aug 19 02:26:20 2012 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Sun Aug 19 02:26:20 2012 : Debug: Listening on proxy address * port 1814
Sun Aug 19 02:26:20 2012 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.0.1.10 port 1645, id=1, length=205
        User-Name = "testuser-2 at vitesse.com"
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "60-73-5C-7C-76-02"
        Calling-Station-Id = "00-12-3F-72-D2-94"
        EAP-Message = 0x02010026016d61637365632d74657374757365722d3240736166656e65742d696e632e636f6d
        Message-Authenticator = 0xf195d2e86b5730bed24d8f131671ae54
        NAS-Port-Type = Ethernet
        NAS-Port = 50102
        NAS-Port-Id = "GigabitEthernet1/0/2"
        NAS-IP-Address = 10.0.1.10
Sun Aug 19 02:26:21 2012 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authorize {...}
Sun Aug 19 02:26:21 2012 : Info: ++[preprocess] returns ok
Sun Aug 19 02:26:21 2012 : Info: ++[chap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[mschap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[digest] returns noop
Sun Aug 19 02:26:21 2012 : Info: [suffix] Looking up realm "vitesse.com" for User-Name = "testuser-2 at vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: [suffix] No such realm "vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: ++[suffix] returns noop
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP packet type response id 1 length 38
Sun Aug 19 02:26:21 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns updated
Sun Aug 19 02:26:21 2012 : Info: ++[files] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[expiration] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[logintime] returns noop
Sun Aug 19 02:26:21 2012 : Info: [pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Sun Aug 19 02:26:21 2012 : Info: ++[pap] returns noop
Sun Aug 19 02:26:21 2012 : Info: Found Auth-Type = EAP
Sun Aug 19 02:26:21 2012 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authenticate {...}
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP Identity
Sun Aug 19 02:26:21 2012 : Info: [eap] processing type tls
Sun Aug 19 02:26:21 2012 : Info: [tls] Requiring client certificate
Sun Aug 19 02:26:21 2012 : Info: [tls] Initiate
Sun Aug 19 02:26:21 2012 : Info: [tls] Start returned 1
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 1 to 10.0.1.10 port 1645
        EAP-Message = 0x010200060d20
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xbf5dac08bf5fa1c3463cf7abb2af0b39
Sun Aug 19 02:26:21 2012 : Info: Finished request 0.
Sun Aug 19 02:26:21 2012 : Debug: Going to the next request
Sun Aug 19 02:26:21 2012 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.0.1.10 port 1645, id=2, length=249
        User-Name = "testuser-2 at vitesse.com"
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "60-73-5C-7C-76-02"
        Calling-Station-Id = "00-12-3F-72-D2-94"
        EAP-Message = 0x020200400d0016030200350100003103025030870d0ec96198dec1b386458ffbe99af21675b8e2b1638343dacb4f9214fa00000a00040005000a002f00350100
        Message-Authenticator = 0xf23c358b48f85f15e82089afd12eebe8
        NAS-Port-Type = Ethernet
        NAS-Port = 50102
        NAS-Port-Id = "GigabitEthernet1/0/2"
        State = 0xbf5dac08bf5fa1c3463cf7abb2af0b39
        NAS-IP-Address = 10.0.1.10
Sun Aug 19 02:26:21 2012 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authorize {...}
Sun Aug 19 02:26:21 2012 : Info: ++[preprocess] returns ok
Sun Aug 19 02:26:21 2012 : Info: ++[chap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[mschap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[digest] returns noop
Sun Aug 19 02:26:21 2012 : Info: [suffix] Looking up realm "vitesse.com" for User-Name = "testuser-2 at vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: [suffix] No such realm "vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: ++[suffix] returns noop
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP packet type response id 2 length 64
Sun Aug 19 02:26:21 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns updated
Sun Aug 19 02:26:21 2012 : Info: ++[files] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[expiration] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[logintime] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[pap] returns noop
Sun Aug 19 02:26:21 2012 : Info: Found Auth-Type = EAP
Sun Aug 19 02:26:21 2012 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authenticate {...}
Sun Aug 19 02:26:21 2012 : Info: [eap] Request found, released from the list
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP/tls
Sun Aug 19 02:26:21 2012 : Info: [eap] processing type tls
Sun Aug 19 02:26:21 2012 : Info: [tls] Authenticate
Sun Aug 19 02:26:21 2012 : Info: [tls] processing EAP-TLS
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_verify returned 7
Sun Aug 19 02:26:21 2012 : Info: [tls] Done initial handshake
Sun Aug 19 02:26:21 2012 : Info: [tls]     (other): before/accept initialization
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: before/accept initialization
Sun Aug 19 02:26:21 2012 : Info: [tls] <<< TLS 1.0 Handshake [length 0035], ClientHello
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 read client hello A
Sun Aug 19 02:26:21 2012 : Info: [tls] >>> TLS 1.0 Handshake [length 002a], ServerHello
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 write server hello A
Sun Aug 19 02:26:21 2012 : Info: [tls] >>> TLS 1.0 Handshake [length 05f6], Certificate
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 write certificate A
Sun Aug 19 02:26:21 2012 : Info: [tls] >>> TLS 1.0 Handshake [length 004f], CertificateRequest
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 write certificate request A
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 flush data
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: Need to read more data: SSLv3 read client certificate A
Sun Aug 19 02:26:21 2012 : Debug: In SSL Handshake Phase
Sun Aug 19 02:26:21 2012 : Debug: In SSL Accept mode
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_process returned 13
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 2 to 10.0.1.10 port 1645
        EAP-Message = 0x010304000dc00000067e160301002a020000260301503001753847006b9e33a31d85bdec393d78996bdc75d7a596a3e3d697788bd00000040016030105f60b0005f20005ef00023c30820238308201c2a003020102020101300d06092a864886f70d0101050500303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d41437365632054657374204341301e170d3033303733303139333030305a170d3133313230313132303030305a303b310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311430120603550403130b74657374
        EAP-Message = 0x2075736572203130819f300d06092a864886f70d010101050003818d0030818902818100ab9b911956942e0a12715c57bd322a6b78d86ed4382baf9e66a36f1dc1fad2e84fd52b6c1b57f1242f7e193441f651716c30a31a2211b50fde30b15c2d4c1ea0a9ac69f19fb6254b4b6b71468ff4722b6a2808198f0915e51b6ea30ab14253dfd3cd726d59544903dfdcc5fea8d3331316e667d7efd82bcc9323be4ee411fd890203010001a36a3068300b0603551d0f0404030205a030590603551d110452305081216d61637365632d74657374757365722d3140736166656e65742d696e632e636f6d82136f6e652e736166656e65742d696e632e636f6d
        EAP-Message = 0x8710200100000000000000000000000000018704c0a80201300d06092a864886f70d0101050500036100a26497f93b0abee71a6ffb524fd324a1e6e3ba017890abf46e05c71688ac0eff48cab05b534c2d98f38e252659d9ae8f032cb7616362cce4e2f6fadf9b16390ec282c575d11822c9ca0197cf4fc7a7735db235dcd499aecd5982c7e2d2ebe0ad0003ad308203a930820333a003020102020100300d06092a864886f70d0101050500303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d41437365632054657374204341301e170d3033303633303139333030305a
        EAP-Message = 0x170d3133303130313132303030305a303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d41437365632054657374204341307c300d06092a864886f70d0101010500036b003068026100a4e38a61b95df958c05e8abef93a339a0a24080401bc1b4a66d3a4e07e45443dac0a90a183b4791a149a4081cad2d25ba897f00d8d0977206754eb240d009c019d5b65d0b1f7055c3350138b1d33b3c0679cf1b21a5c8fb201810c6106a91c770203010001a38201fa308201f6301b0603551d230414301280104d794964656e7469666965722f31303030190603551d0e04120410
        EAP-Message = 0x4d794964656e746966696572
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xbf5dac08be5ea1c3463cf7abb2af0b39
Sun Aug 19 02:26:21 2012 : Info: Finished request 1.
Sun Aug 19 02:26:21 2012 : Debug: Going to the next request
Sun Aug 19 02:26:21 2012 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.0.1.10 port 1645, id=3, length=191
        User-Name = "testuser-2 at vitesse.com"
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "60-73-5C-7C-76-02"
        Calling-Station-Id = "00-12-3F-72-D2-94"
        EAP-Message = 0x020300060d00
        Message-Authenticator = 0x5a3802777158deae3809afda6d3ea9b1
        NAS-Port-Type = Ethernet
        NAS-Port = 50102
        NAS-Port-Id = "GigabitEthernet1/0/2"
        State = 0xbf5dac08be5ea1c3463cf7abb2af0b39
        NAS-IP-Address = 10.0.1.10
Sun Aug 19 02:26:21 2012 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authorize {...}
Sun Aug 19 02:26:21 2012 : Info: ++[preprocess] returns ok
Sun Aug 19 02:26:21 2012 : Info: ++[chap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[mschap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[digest] returns noop
Sun Aug 19 02:26:21 2012 : Info: [suffix] Looking up realm "vitesse.com" for User-Name = "testuser-2 at vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: [suffix] No such realm "vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: ++[suffix] returns noop
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP packet type response id 3 length 6
Sun Aug 19 02:26:21 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns updated
Sun Aug 19 02:26:21 2012 : Info: ++[files] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[expiration] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[logintime] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[pap] returns noop
Sun Aug 19 02:26:21 2012 : Info: Found Auth-Type = EAP
Sun Aug 19 02:26:21 2012 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authenticate {...}
Sun Aug 19 02:26:21 2012 : Info: [eap] Request found, released from the list
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP/tls
Sun Aug 19 02:26:21 2012 : Info: [eap] processing type tls
Sun Aug 19 02:26:21 2012 : Info: [tls] Authenticate
Sun Aug 19 02:26:21 2012 : Info: [tls] processing EAP-TLS
Sun Aug 19 02:26:21 2012 : Info: [tls] Received TLS ACK
Sun Aug 19 02:26:21 2012 : Info: [tls] ACK handshake fragment handler
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_verify returned 1
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_process returned 13
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 3 to 10.0.1.10 port 1645
        EAP-Message = 0x010402920d800000067e2f313030300b0603551d0f040403020186302e0603551d1104273025811d6d61637365632d74657374636140736166656e65742d696e632e636f6d87040102030430120603551d130101ff040830060101ff020100300f0603551d240408300680010a81010a308201110603551d1f04820108308201043081a6a057a055a4363034310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e310d300b0603550403130443524c31861b6c6461703a2f2f6c6461702e736166656e65742d696e632e636f6d81020640a247a4453043310b300906035504061302464931163014060355040a
        EAP-Message = 0x130d536166654e65742c20496e632e311c301a060355040313134d414373656320546573742043412043524c323059a00fa10d300b0603550403130443524c318102013ea242a440303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d4143736563205465737420434130450603551d25043e303c06082b0601050507030106082b0601050507030206082b0601050507030306082b0601050507030406082b0601050507030806082b06010505080202300d06092a864886f70d0101050500036100146a670232808c5282112a6e1942babe776bda591a6c3b8257a193a3
        EAP-Message = 0x0a80da48b6f2aa9f3d38b3e58a5062456fbe16ec873f162e90f63eab1ffee100a779e233e147403fec8b700fd4e8965647ce7118fedb49633b301abc2bbca663fde2ccbe160301004f0d00004702010200420040303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d414373656320546573742043410e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xbf5dac08bd59a1c3463cf7abb2af0b39
Sun Aug 19 02:26:21 2012 : Info: Finished request 2.
Sun Aug 19 02:26:21 2012 : Debug: Going to the next request
Sun Aug 19 02:26:21 2012 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.0.1.10 port 1645, id=4, length=1227
        User-Name = "testuser-2 at vitesse.com"
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "60-73-5C-7C-76-02"
        Calling-Station-Id = "00-12-3F-72-D2-94"
        EAP-Message = 0x0204040a0dc000000737160301067c0b0005f20005ef00023c30820238308201c2a003020102020102300d06092a864886f70d0101050500303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d41437365632054657374204341301e170d3033303733303139333030305a170d3133313230313132303030305a303b310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311430120603550403130b746573742075736572203230819f300d06092a864886f70d010101050003818d0030818902818100c0908d6bf5ce448dfe2717
        EAP-Message = 0x23c9c3712f43d3d07f0163d289548985b054ad15a26bacfa0f183b7dbc78d650f7e450ffccb1dbddccfe4334b7447ff65302404dcbf022c6723e42a20ea2b6de8af011c7688bba1acc9b50031c1dc12b9a912a58dd64dfb11e1013403dda99c4aa7edbb81438f77ce5203862b7c8369b1a9189c0650203010001a36a3068300b0603551d0f0404030205a030590603551d110452305081216d61637365632d74657374757365722d3240736166656e65742d696e632e636f6d821374776f2e736166656e65742d696e632e636f6d8710200100000000000000000000000000028704c0a80202300d06092a864886f70d0101050500036100341b88f683
        EAP-Message = 0xf75e9f1a4fffc650833014095248929c33300518af5d7f8b9b16b7f7f4a11c0b655328a216c43a9fad4c108041aa6d5d53719b4f694cb757f7b490dcf191c0aebe9c1880bbecf77440da96a7829c5f8daa13c31f3506bcb38d49090003ad308203a930820333a003020102020100300d06092a864886f70d0101050500303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d41437365632054657374204341301e170d3033303633303139333030305a170d3133303130313132303030305a303e310b300906035504061302464931163014060355040a130d536166654e65
        EAP-Message = 0x742c20496e632e311730150603550403130e4d41437365632054657374204341307c300d06092a864886f70d0101010500036b003068026100a4e38a61b95df958c05e8abef93a339a0a24080401bc1b4a66d3a4e07e45443dac0a90a183b4791a149a4081cad2d25ba897f00d8d0977206754eb240d009c019d5b65d0b1f7055c3350138b1d33b3c0679cf1b21a5c8fb201810c6106a91c770203010001a38201fa308201f6301b0603551d230414301280104d794964656e7469666965722f31303030190603551d0e041204104d794964656e7469666965722f313030300b0603551d0f040403020186302e0603551d1104273025811d6d61637365
        EAP-Message = 0x632d74657374636140736166656e65742d696e632e63
        Message-Authenticator = 0x5e998e1bb96fb1db2f0db8f8c71e5961
        NAS-Port-Type = Ethernet
        NAS-Port = 50102
        NAS-Port-Id = "GigabitEthernet1/0/2"
        State = 0xbf5dac08bd59a1c3463cf7abb2af0b39
        NAS-IP-Address = 10.0.1.10
Sun Aug 19 02:26:21 2012 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authorize {...}
Sun Aug 19 02:26:21 2012 : Info: ++[preprocess] returns ok
Sun Aug 19 02:26:21 2012 : Info: ++[chap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[mschap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[digest] returns noop
Sun Aug 19 02:26:21 2012 : Info: [suffix] Looking up realm "vitesse.com" for User-Name = "testuser-2 at vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: [suffix] No such realm "vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: ++[suffix] returns noop
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP packet type response id 4 length 253
Sun Aug 19 02:26:21 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns updated
Sun Aug 19 02:26:21 2012 : Info: ++[files] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[expiration] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[logintime] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[pap] returns noop
Sun Aug 19 02:26:21 2012 : Info: Found Auth-Type = EAP
Sun Aug 19 02:26:21 2012 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authenticate {...}
Sun Aug 19 02:26:21 2012 : Info: [eap] Request found, released from the list
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP/tls
Sun Aug 19 02:26:21 2012 : Info: [eap] processing type tls
Sun Aug 19 02:26:21 2012 : Info: [tls] Authenticate
Sun Aug 19 02:26:21 2012 : Info: [tls] processing EAP-TLS
Sun Aug 19 02:26:21 2012 : Debug:   TLS Length 1847
Sun Aug 19 02:26:21 2012 : Info: [tls] Received EAP-TLS First Fragment of the message
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_verify returned 9
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_process returned 13
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 4 to 10.0.1.10 port 1645
        EAP-Message = 0x010500060d00
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xbf5dac08bc58a1c3463cf7abb2af0b39
Sun Aug 19 02:26:21 2012 : Info: Finished request 3.
Sun Aug 19 02:26:21 2012 : Debug: Going to the next request
Sun Aug 19 02:26:21 2012 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.0.1.10 port 1645, id=5, length=1020
        User-Name = "testuser-2 at vitesse.com"
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "60-73-5C-7C-76-02"
        Calling-Station-Id = "00-12-3F-72-D2-94"
        EAP-Message = 0x0205033d0d006f6d87040102030430120603551d130101ff040830060101ff020100300f0603551d240408300680010a81010a308201110603551d1f04820108308201043081a6a057a055a4363034310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e310d300b0603550403130443524c31861b6c6461703a2f2f6c6461702e736166656e65742d696e632e636f6d81020640a247a4453043310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311c301a060355040313134d414373656320546573742043412043524c323059a00fa10d300b0603550403130443
        EAP-Message = 0x524c318102013ea242a440303e310b300906035504061302464931163014060355040a130d536166654e65742c20496e632e311730150603550403130e4d4143736563205465737420434130450603551d25043e303c06082b0601050507030106082b0601050507030206082b0601050507030306082b0601050507030406082b0601050507030806082b06010505080202300d06092a864886f70d0101050500036100146a670232808c5282112a6e1942babe776bda591a6c3b8257a193a30a80da48b6f2aa9f3d38b3e58a5062456fbe16ec873f162e90f63eab1ffee100a779e233e147403fec8b700fd4e8965647ce7118fedb49633b301abc2b
        EAP-Message = 0xbca663fde2ccbe100000820080991c6dad9b5639158a2fe0c9bda6baa62455a763186643845766fa1358fd92b473a113c151dcaeac42406b84fe16c4668971d1cbffbc521cbf2ddd8c9071938ffd5d6e9288fc4c176e81acbe350b139347cc65562bb500d7198e359c034d2a66a2db3c72b010e209e93735080021351e95ff83a0ebc30ee16a2aa9eab9de995b16030100860f000082008012b9a39249645b62c99c54ae2d81a8fc271577de24350b1f4c9bef50a782fc262ef30f88bb0bec36fdc1d4f4897c79c2e9c9c81a07c49214fd84f96064d5e357425a98e9540b8bf6702c544614301d19ea35b3d84004b6e8518e8dbe6fbfbc461b578bacae
        EAP-Message = 0xd6b8cee1f1677ce191e0730f3de81c0853c8665441135eb75ff6f414030100010116030100206becd2e443bb3a2c2a84c2e37e2670e6a9232effb96d378b293d3382c6f90cfe
        Message-Authenticator = 0xd218a2b63ffd29526e666f2a11250f7e
        NAS-Port-Type = Ethernet
        NAS-Port = 50102
        NAS-Port-Id = "GigabitEthernet1/0/2"
        State = 0xbf5dac08bc58a1c3463cf7abb2af0b39
        NAS-IP-Address = 10.0.1.10
Sun Aug 19 02:26:21 2012 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authorize {...}
Sun Aug 19 02:26:21 2012 : Info: ++[preprocess] returns ok
Sun Aug 19 02:26:21 2012 : Info: ++[chap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[mschap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[digest] returns noop
Sun Aug 19 02:26:21 2012 : Info: [suffix] Looking up realm "vitesse.com" for User-Name = "testuser-2 at vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: [suffix] No such realm "vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: ++[suffix] returns noop
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP packet type response id 5 length 253
Sun Aug 19 02:26:21 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns updated
Sun Aug 19 02:26:21 2012 : Info: ++[files] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[expiration] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[logintime] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[pap] returns noop
Sun Aug 19 02:26:21 2012 : Info: Found Auth-Type = EAP
Sun Aug 19 02:26:21 2012 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authenticate {...}
Sun Aug 19 02:26:21 2012 : Info: [eap] Request found, released from the list
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP/tls
Sun Aug 19 02:26:21 2012 : Info: [eap] processing type tls
Sun Aug 19 02:26:21 2012 : Info: [tls] Authenticate
Sun Aug 19 02:26:21 2012 : Info: [tls] processing EAP-TLS
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_verify returned 7
Sun Aug 19 02:26:21 2012 : Info: [tls] Done initial handshake
Sun Aug 19 02:26:21 2012 : Info: [tls] <<< TLS 1.0 Handshake [length 05f6], Certificate
Sun Aug 19 02:26:21 2012 : Info: [tls] chain-depth=1,
Sun Aug 19 02:26:21 2012 : Info: [tls] error=0
Sun Aug 19 02:26:21 2012 : Info: [tls] --> User-Name = testuser-2 at vitesse.com
Sun Aug 19 02:26:21 2012 : Info: [tls] --> BUF-Name = MACsec Test CA
Sun Aug 19 02:26:21 2012 : Info: [tls] --> subject = /C=FI/O=vitesse, Inc./CN=MACsec Test CA
Sun Aug 19 02:26:21 2012 : Info: [tls] --> issuer  = /C=FI/O=vitesse, Inc./CN=MACsec Test CA
Sun Aug 19 02:26:21 2012 : Info: [tls] --> verify return:1
Sun Aug 19 02:26:21 2012 : Info: [tls] chain-depth=0,
Sun Aug 19 02:26:21 2012 : Info: [tls] error=0
Sun Aug 19 02:26:21 2012 : Info: [tls] --> User-Name = testuser-2 at vitesse.com
Sun Aug 19 02:26:21 2012 : Info: [tls] --> BUF-Name = test user 2
Sun Aug 19 02:26:21 2012 : Info: [tls] --> subject = /C=FI/O=vitesse, Inc./CN=test user 2
Sun Aug 19 02:26:21 2012 : Info: [tls] --> issuer  = /C=FI/O=vitesse, Inc./CN=MACsec Test CA
Sun Aug 19 02:26:21 2012 : Info: [tls] --> verify return:1
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 read client certificate A
Sun Aug 19 02:26:21 2012 : Info: [tls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 read client key exchange A
Sun Aug 19 02:26:21 2012 : Info: [tls] <<< TLS 1.0 Handshake [length 0086], CertificateVerify
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 read certificate verify A
Sun Aug 19 02:26:21 2012 : Info: [tls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
Sun Aug 19 02:26:21 2012 : Info: [tls] <<< TLS 1.0 Handshake [length 0010], Finished
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 read finished A
Sun Aug 19 02:26:21 2012 : Info: [tls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 write change cipher spec A
Sun Aug 19 02:26:21 2012 : Info: [tls] >>> TLS 1.0 Handshake [length 0010], Finished
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 write finished A
Sun Aug 19 02:26:21 2012 : Info: [tls]     TLS_accept: SSLv3 flush data
Sun Aug 19 02:26:21 2012 : Info: [tls]     (other): SSL negotiation finished successfully
Sun Aug 19 02:26:21 2012 : Debug: SSL Connection Established
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_process returned 13
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 5 to 10.0.1.10 port 1645
        EAP-Message = 0x010600350d800000002b140301000101160301002047abaee62e85431c72513413505ad33876d0963b6d29a6f22f4bcb8fcc6bd416
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xbf5dac08bb5ba1c3463cf7abb2af0b39
Sun Aug 19 02:26:21 2012 : Info: Finished request 4.
Sun Aug 19 02:26:21 2012 : Debug: Going to the next request
Sun Aug 19 02:26:21 2012 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.0.1.10 port 1645, id=6, length=191
        User-Name = "testuser-2 at vitesse.com"
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "60-73-5C-7C-76-02"
        Calling-Station-Id = "00-12-3F-72-D2-94"
        EAP-Message = 0x020600060d00
        Message-Authenticator = 0x6197189826a6fae1876e0cdf6eef6d0c
        NAS-Port-Type = Ethernet
        NAS-Port = 50102
        NAS-Port-Id = "GigabitEthernet1/0/2"
        State = 0xbf5dac08bb5ba1c3463cf7abb2af0b39
        NAS-IP-Address = 10.0.1.10
Sun Aug 19 02:26:21 2012 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authorize {...}
Sun Aug 19 02:26:21 2012 : Info: ++[preprocess] returns ok
Sun Aug 19 02:26:21 2012 : Info: ++[chap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[mschap] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[digest] returns noop
Sun Aug 19 02:26:21 2012 : Info: [suffix] Looking up realm "vitesse.com" for User-Name = "testuser-2 at vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: [suffix] No such realm "vitesse.com"
Sun Aug 19 02:26:21 2012 : Info: ++[suffix] returns noop
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP packet type response id 6 length 6
Sun Aug 19 02:26:21 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sun Aug 19 02:26:21 2012 : Info: ++[eap] returns updated
Sun Aug 19 02:26:21 2012 : Info: ++[files] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[expiration] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[logintime] returns noop
Sun Aug 19 02:26:21 2012 : Info: ++[pap] returns noop
Sun Aug 19 02:26:21 2012 : Info: Found Auth-Type = EAP
Sun Aug 19 02:26:21 2012 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Sun Aug 19 02:26:21 2012 : Info: +- entering group authenticate {...}
Sun Aug 19 02:26:21 2012 : Info: [eap] Request found, released from the list
Sun Aug 19 02:26:21 2012 : Info: [eap] EAP/tls
Sun Aug 19 02:26:21 2012 : Info: [eap] processing type tls
Sun Aug 19 02:26:21 2012 : Info: [tls] Authenticate
Sun Aug 19 02:26:21 2012 : Info: [tls] processing EAP-TLS
Sun Aug 19 02:26:21 2012 : Info: [tls] Received TLS ACK
Sun Aug 19 02:26:21 2012 : Info: [tls] ACK handshake is finished
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_verify returned 3
Sun Aug 19 02:26:21 2012 : Info: [tls] eaptls_process returned 3
Sun Aug 19 02:26:21 2012 : Info: [tls] Adding user data to cached session
Segmentation Fault

Thanks,
Srinivas B

-----Original Message-----
From: freeradius-users-bounces+sbandari=vitesse.com at lists.freeradius.org [mailto:freeradius-users-bounces+sbandari=vitesse.com at lists.freeradius.org] On Behalf Of Alan DeKok
Sent: 18 February 2013 19:49
To: FreeRadius users mailing list
Subject: Re: AVP EAP-KEY name support in FR

Srinu Bandari wrote:
> And New one: Here the tls state machine goes from Access-Request to
> Access-Rejected and then ends with segmentation fault

  The debug log doesn't show a SEGV...

  But there was an unrelated issue.  Please do "git pull" for the v2.x.x. branch, and try again.  I've fixed the bug that caused the early reject.

> What could have gone wrong??

  Another bug.

  Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
CONFIDENTIALITY NOTICE: This e-mail message, including any attachments, is for the sole use of the intended recipient(s) and may contain confidential and privileged information. Any unauthorized review, use, disclosure or distribution is prohibited. If you are not the intended recipient, please contact the sender by reply e-mail and destroy all copies of the original message.


More information about the Freeradius-Users mailing list