[Fwd: mschapV2 problem]

Cristian Novac cristian.novac at alcatel-lucent.ro
Wed Apr 30 16:00:13 CEST 2008


Cristian Novac wrote:
>
>
> ------------------------------------------------------------------------
>
> Subject:
> mschapV2 problem
> From:
> Cristian Novac <Cristian.Novac at mrc.alcatel.ro>
> Date:
> Wed, 30 Apr 2008 16:09:11 +0300
> To:
> freeradius-users at lists.freeradius.org
>
> To:
> freeradius-users at lists.freeradius.org
>
>
> Hello,
>
> I attached two log files obtained from freeradius.
> For both were used the same configuration files in server;in fact the 
> server wasn't stopped at all.
> But, if client choose to do chap, in Acces-Accept received from server 
> I will get all the attributes I set up in users file(see 
> chap.logcopyed attached) and if client choose to do mschapv2, in 
> Acces-Accept received from server I won't get any of the attributes I 
> set up in users file(see chapv2.log attached)
> WHY???
Can anyone help telling why attributes are not included in Acces-Accept 
when client chooses to do mschapV2????

>
> Thank you!
> ------------------------------------------------------------------------
>
> [root at AAA1 RADIUS-102.INSTALLED]# sbin/radiusd -X
> Starting - reading configuration files ...
> reread_config:  reading radiusd.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/proxy.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/clients.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/snmp.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/eap.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/sql.conf
>  main: prefix = "/udir/RADIUS-102.INSTALLED/"
>  main: localstatedir = "/udir/RADIUS-102.INSTALLED//var"
>  main: logdir = "/udir/RADIUS-102.INSTALLED//var/log/radius"
>  main: libdir = "/udir/RADIUS-102.INSTALLED//lib"
>  main: radacctdir = "/udir/RADIUS-102.INSTALLED//var/log/radius/radacct"
>  main: hostname_lookups = no
>  main: max_request_time = 30
>  main: cleanup_delay = 5
>  main: max_requests = 1024
>  main: delete_blocked_requests = 0
>  main: port = 0
>  main: allow_core_dumps = no
>  main: log_stripped_names = no
>  main: log_file = "/udir/RADIUS-102.INSTALLED//var/log/radius/radius.log"
>  main: log_auth = no
>  main: log_auth_badpass = no
>  main: log_auth_goodpass = no
>  main: pidfile = "/udir/RADIUS-102.INSTALLED//var/run/radiusd/radiusd.pid"
>  main: user = "(null)"
>  main: group = "(null)"
>  main: usercollide = no
>  main: lower_user = "no"
>  main: lower_pass = "no"
>  main: nospace_user = "no"
>  main: nospace_pass = "no"
>  main: checkrad = "/udir/RADIUS-102.INSTALLED//sbin/checkrad"
>  main: proxy_requests = yes
>  proxy: retry_delay = 5
>  proxy: retry_count = 3
>  proxy: synchronous = no
>  proxy: default_fallback = yes
>  proxy: dead_time = 120
>  proxy: post_proxy_authorize = yes
>  proxy: wake_all_if_all_dead = no
>  security: max_attributes = 200
>  security: reject_delay = 1
>  security: status_server = no
>  main: debug_level = 0
> read_config_files:  reading dictionary
> read_config_files:  reading naslist
> Using deprecated naslist file.  Support for this will go away soon.
> read_config_files:  reading clients
> read_config_files:  reading realms
> radiusd:  entering modules setup
> Module: Library search path is /udir/RADIUS-102.INSTALLED/lib
> Module: Loaded exec
>  exec: wait = yes
>  exec: program = "(null)"
>  exec: input_pairs = "request"
>  exec: output_pairs = "(null)"
>  exec: packet_type = "(null)"
> rlm_exec: Wait=yes but no output defined. Did you mean output=none?
> Module: Instantiated exec (exec)
> Module: Loaded expr
> Module: Instantiated expr (expr)
> Module: Loaded PAP
>  pap: encryption_scheme = "crypt"
> Module: Instantiated pap (pap)
> Module: Loaded CHAP
> Module: Instantiated chap (chap)
> Module: Loaded MS-CHAP
>  mschap: use_mppe = yes
>  mschap: require_encryption = no
>  mschap: require_strong = no
>  mschap: with_ntdomain_hack = no
>  mschap: passwd = "(null)"
>  mschap: authtype = "MS-CHAP"
>  mschap: ntlm_auth = "(null)"
> Module: Instantiated mschap (mschap)
> Module: Loaded System
>  unix: cache = no
>  unix: passwd = "(null)"
>  unix: shadow = "(null)"
>  unix: group = "(null)"
>  unix: radwtmp = "/udir/RADIUS-102.INSTALLED//var/log/radius/radwtmp"
>  unix: usegroup = no
>  unix: cache_reload = 600
> Module: Instantiated unix (unix)
> Module: Loaded eap
>  eap: default_eap_type = "ttls"
>  eap: timer_expire = 60
>  eap: ignore_unknown_eap_types = no
>  eap: cisco_accounting_username_bug = no
> rlm_eap: Loaded and initialized type md5
>  tls: rsa_key_exchange = no
>  tls: dh_key_exchange = yes
>  tls: rsa_key_length = 512
>  tls: dh_key_length = 512
>  tls: verify_depth = 0
>  tls: CA_path = "(null)"
>  tls: pem_file_type = yes
>  tls: private_key_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/server-key.pem"
>  tls: certificate_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/server.pem"
>  tls: CA_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/ca-cert.pem"
>  tls: private_key_password = "asb#1234"
>  tls: dh_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/dh"
>  tls: random_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/random"
>  tls: fragment_size = 1024
>  tls: include_length = yes
>  tls: check_crl = yes
>  tls: check_cert_cn = "(null)"
>  tls: session_resume = 1
> rlm_eap: Loaded and initialized type tls
>  ttls: default_eap_type = "mschapv2"
>  ttls: copy_request_to_tunnel = yes
>  ttls: use_tunneled_reply = yes
> rlm_eap: Loaded and initialized type ttls
>  sim: fast_reauth = no
>  sim: success_notification = no
> rlm_eap_sim: fast_reauth = 0
> rlm_eap_sim: success_notification = 0
> rlm_eap: Loaded and initialized type sim
>  mschapv2: with_ntdomain_hack = no
> rlm_eap: Loaded and initialized type mschapv2
> Module: Instantiated eap (eap)
> Module: Loaded preprocess
>  preprocess: huntgroups = "/udir/RADIUS-102.INSTALLED//etc/raddb/huntgroups"
>  preprocess: hints = "/udir/RADIUS-102.INSTALLED//etc/raddb/hints"
>  preprocess: with_ascend_hack = no
>  preprocess: ascend_channels_per_line = 23
>  preprocess: with_ntdomain_hack = no
>  preprocess: with_specialix_jetstream_hack = no
>  preprocess: with_cisco_vsa_hack = no
> Module: Instantiated preprocess (preprocess)
> Module: Loaded realm
>  realm: format = "suffix"
>  realm: delimiter = "@"
>  realm: ignore_default = no
>  realm: ignore_null = no
> Module: Instantiated realm (suffix)
> Module: Loaded files
>  files: usersfile = "/udir/RADIUS-102.INSTALLED//etc/raddb/users"
>  files: acctusersfile = "/udir/RADIUS-102.INSTALLED//etc/raddb/acct_users"
>  files: preproxy_usersfile = "/udir/RADIUS-102.INSTALLED//etc/raddb/preproxy_users"
>  files: compat = "no"
> Module: Instantiated files (files)
> Module: Loaded Acct-Unique-Session-Id
>  acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
> Module: Instantiated acct_unique (acct_unique)
> Module: Loaded detail
>  detail: detailfile = "/udir/RADIUS-102.INSTALLED//var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
>  detail: detailperm = 384
>  detail: dirperm = 493
>  detail: locking = no
> Module: Instantiated detail (detail)
> Module: Loaded radutmp
>  radutmp: filename = "/udir/RADIUS-102.INSTALLED//var/log/radius/radutmp"
>  radutmp: username = "%{User-Name}"
>  radutmp: case_sensitive = yes
>  radutmp: check_with_nas = yes
>  radutmp: perm = 384
>  radutmp: callerid = yes
> Module: Instantiated radutmp (radutmp)
> Listening on authentication *:1812
> Listening on accounting *:1813
> Listening on proxy *:1814
> Ready to process requests.
> rad_recv: Access-Request packet from host 10.10.10.30:36608, id=1, length=166
>         Calling-Station-Id = "00-17-C4-27-4E-F6"
>         Message-Authenticator = 0x7d3c069900bb8893673f740ea1590d83
>         EAP-Message = 0x02b4001601616e6f6e796d6f7573406173622e636f6d
>         Framed-MTU = 3795
>         User-Name = "anonymous at asb.com"
>         NAS-IP-Address = 10.10.10.30
>         WiMAX-Attr-46 = 0x00111111323200
>         Service-Type = Framed-User
>         WiMAX-Attr-1 = 0x000105312e3202030203030a
>         WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 0
>   modcall[authorize]: module "preprocess" returns ok for request 0
>   modcall[authorize]: module "chap" returns noop for request 0
>   modcall[authorize]: module "mschap" returns noop for request 0
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 0
>   rlm_eap: EAP packet type response id 180 length 22
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 0
>   modcall[authorize]: module "files" returns notfound for request 0
> modcall: group authorize returns updated for request 0
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 0
>   rlm_eap: EAP Identity
> rlm_eap: try to find eap sim reauthentication_id anonymous at asb.com
>   rlm_eap: processing type tls
>   rlm_eap_tls: Initiate
>   rlm_eap_tls: Start returned 1
>   modcall[authenticate]: module "eap" returns handled for request 0
> modcall: group authenticate returns handled for request 0
> Sending Access-Challenge of id 1 to 10.10.10.30:36608
>         EAP-Message = 0x01b500061520
>         Message-Authenticator = 0x00000000000000000000000000000000
>         State = 0xba61ca9b52cb6ff25601201d4ca728fd
> Finished request 0
> Going to the next request
> --- Walking the entire request list ---
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 10.10.10.30:36608, id=2, length=270
>         Calling-Station-Id = "00-17-C4-27-4E-F6"
>         Message-Authenticator = 0x77cc0b660630b76c95898f04a1bbd572
>         EAP-Message = 0x02b5006c150016030100610100005d030148186938abaff4e966a0d8ebeb3db10cd8600c6ee7e67fc1f69021a3e53778f200003600390038003500160013000a00330032002f0007006600050004006300620061001500120009006500640060001400110008000600030100
>         Framed-MTU = 3795
>         User-Name = "anonymous at asb.com"
>         NAS-IP-Address = 10.10.10.30
>         State = 0xba61ca9b52cb6ff25601201d4ca728fd
>         WiMAX-Attr-46 = 0x00111111323200
>         Service-Type = Framed-User
>         WiMAX-Attr-1 = 0x000105312e3202030203030a
>         WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 1
>   modcall[authorize]: module "preprocess" returns ok for request 1
>   modcall[authorize]: module "chap" returns noop for request 1
>   modcall[authorize]: module "mschap" returns noop for request 1
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 1
>   rlm_eap: EAP packet type response id 181 length 108
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 1
>   modcall[authorize]: module "files" returns notfound for request 1
> modcall: group authorize returns updated for request 1
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 1
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
>   eaptls_verify returned 7
>   rlm_eap_tls: Done initial handshake
>     (other): before/accept initialization
>     TLS_accept: before/accept initialization
>   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0061], ClientHello
>     TLS_accept: SSLv3 read client hello A
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
>     TLS_accept: SSLv3 write server hello A
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0438], Certificate
>     TLS_accept: SSLv3 write certificate A
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 010d], ServerKeyExchange
>     TLS_accept: SSLv3 write key exchange A
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
>     TLS_accept: SSLv3 write server done A
>     TLS_accept: SSLv3 flush data
>     TLS_accept:error in SSLv3 read client certificate A
> In SSL Handshake Phase
> In SSL Accept mode
> hit in SSL is 0
>   eaptls_process returned 13
>   handler->eap_ds->request->code 1
>   modcall[authenticate]: module "eap" returns handled for request 1
> modcall: group authenticate returns handled for request 1
> Sending Access-Challenge of id 2 to 10.10.10.30:36608
>         EAP-Message = 0x01b6040a15c0000005a7160301004a02000046030148186471d3c44b35d8e2bdd49c4dc8d27bc5aabd5be2a5058e303b68caf56aa82036f402e08d1507352a49b58cd11392dc7e533492a034fdfa428b08e216fed56a00390016030104380b000434000431000218308202143082017d020105300d06092a864886f70d01010405003050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b3009060355040313026361301e170d3037313131393038303533305a170d3038313131383038303533305a3055310b3009060355
>         EAP-Message = 0x040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b13037264723110300e060355040313076173622e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100b0634f379d38220d960a6f7c80abd51a2b7a9cac830613ec665fae7c1ca6215b60ea222142e7c6832c6d344dae7bc5cc3385db768824fbc63c93bfe9c79af932248380799e7f7bbb1ad953ac64adf590f2af0d02a5440e7a67769c92fcb74b4e20cb6776513eb13297599961c1be81ec0c6633ef709da026e96feebe5d0ab5e70203010001300d06092a864886f70d010104
>         EAP-Message = 0x05000381810069e6b80739a38b06b15a28ace28510b0fc9a26d291c4b9ab9102bc349827197bce7bf4d3bca49e5a5bc61da2b1d9f96e504a469deaf4cf1d915b844f8506ccdd9e995654aafca0e93598b19ab21667ecb40617b4a0e80816a89e3924aeb0c53d93dad0a14e8c678197708ad92f1769673a4499d5ec811a090253bf18df6dd5b50002133082020f30820178020100300d06092a864886f70d01010405003050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b3009060355040313026361301e170d30373131
>         EAP-Message = 0x31393038303433315a170d3038313131383038303433315a3050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b300906035504031302636130819f300d06092a864886f70d010101050003818d0030818902818100dc70ad4fc5351431abb49e7f58f1d25e90634ea6dcb7f5f440ac2059ccb4d5b47a0c6c1c62014d96c48cb295344fa36bea1dfeb171dab4aa2238087937ac41e513c49af623af2ab3170628cb1d954fdc4587171caae000e325620f5d35aee55712d8f28af71e1be41bed4970bc00c4320a3208bae176
>         EAP-Message = 0x2d816730040ada827c0d0203010001300d06092a8648
>         Message-Authenticator = 0x00000000000000000000000000000000
>         State = 0x602b39b6bf596b689a9c8722b33c15fa
> Finished request 1
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 10.10.10.30:36608, id=3, length=168
>         Calling-Station-Id = "00-17-C4-27-4E-F6"
>         Message-Authenticator = 0x5f5b2e255b96a1f4a454db5037690ef6
>         EAP-Message = 0x02b600061500
>         Framed-MTU = 3795
>         User-Name = "anonymous at asb.com"
>         NAS-IP-Address = 10.10.10.30
>         State = 0x602b39b6bf596b689a9c8722b33c15fa
>         WiMAX-Attr-46 = 0x00111111323200
>         Service-Type = Framed-User
>         WiMAX-Attr-1 = 0x000105312e3202030203030a
>         WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 2
>   modcall[authorize]: module "preprocess" returns ok for request 2
>   modcall[authorize]: module "chap" returns noop for request 2
>   modcall[authorize]: module "mschap" returns noop for request 2
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 2
>   rlm_eap: EAP packet type response id 182 length 6
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 2
>   modcall[authorize]: module "files" returns notfound for request 2
> modcall: group authorize returns updated for request 2
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 2
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
> rlm_eap_tls: Received EAP-TLS ACK message
>   rlm_eap_tls: ack handshake fragment handler
>   eaptls_verify returned 1
>   eaptls_process returned 13
>   handler->eap_ds->request->code 1
>   modcall[authenticate]: module "eap" returns handled for request 2
> modcall: group authenticate returns handled for request 2
> Sending Access-Challenge of id 3 to 10.10.10.30:36608
>         EAP-Message = 0x01b701b11580000005a786f70d010104050003818100321f6dace1aa2f6e55d16f64eb6363393119b3da5c41a7127c7b46e0931d115b6ecb9f52a33868ab8e969dc418740767936cb9f9da02837b868ba824fcad2df8fe3a2fe5cff8dac483603ce312e0218bb93681b208d15fe55ac185416d56696c75d5dd0d8981f3b49962b3b23608fd7010e0ccd32501a7240ec82973066c7332160301010d0c0001090040ea491ab5e523f0f500b96463241287517f2ef085934a4977d6d7484bdfd4dadf7eb552b0e7e3154925eea5c6ad362d72e39a694dfaf9a0bc58dc18aa0e638f0b0001020040d53de1ff1fa11fa362939e46eea0d8fcb3f2dae937d80e
>         EAP-Message = 0xf12c16be1d97147d2a813444501aca6c4c68dc8d6ecf5843f34b1a97bc4e8ad389273f9d7bda810c8200804c469e710f673e55b66208bc8b6b4827d01983e327ac390cb640e2282e1d6d103af7fd713228efa8f47d9640b9e9e9b1a78281253026d72be8ea192c7be32e4aec8ef75048dcf544b47ad84044e171824783f4e94b02281f977c751a696cb5315914202382672ee63a86ee25a3afc799d26410a255d7cb9b514bc0e45fd7fb0d16030100040e000000
>         Message-Authenticator = 0x00000000000000000000000000000000
>         State = 0xde4a9958375d68dad732478440967874
> Finished request 2
> Going to the next request
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 10.10.10.30:36608, id=4, length=302
>         Calling-Station-Id = "00-17-C4-27-4E-F6"
>         Message-Authenticator = 0xb72fd1d173bbc40e322082aa7ee4d4f0
>         EAP-Message = 0x02b7008c1500160301004610000042004046944e539d611e1e48d56244c319f6ebae7e2128aa69620674300bcc69a1ca557bbc09bf1c92b6c71632f1393bccbcd40737407924b86ca4ed79600116af5f3b14030100010116030100309155ed81299ee66d29e6411f190129c50bf037508aa342d197199fd132dc5784cd41b6ab84e3ff9b0eee94ead944884c
>         Framed-MTU = 3795
>         User-Name = "anonymous at asb.com"
>         NAS-IP-Address = 10.10.10.30
>         State = 0xde4a9958375d68dad732478440967874
>         WiMAX-Attr-46 = 0x00111111323200
>         Service-Type = Framed-User
>         WiMAX-Attr-1 = 0x000105312e3202030203030a
>         WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 3
>   modcall[authorize]: module "preprocess" returns ok for request 3
>   modcall[authorize]: module "chap" returns noop for request 3
>   modcall[authorize]: module "mschap" returns noop for request 3
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 3
>   rlm_eap: EAP packet type response id 183 length 140
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 3
>   modcall[authorize]: module "files" returns notfound for request 3
> modcall: group authorize returns updated for request 3
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 3
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
>   eaptls_verify returned 7
>   rlm_eap_tls: Done initial handshake
>   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
>     TLS_accept: SSLv3 read client key exchange A
>   rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
>   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
>     TLS_accept: SSLv3 read finished A
>   rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
>     TLS_accept: SSLv3 write change cipher spec A
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
>     TLS_accept: SSLv3 write finished A
>     TLS_accept: SSLv3 flush data
>     (other): SSL negotiation finished successfully
> SSL Connection Established
> sesssion resume success is 0
> hit in SSL is 0
>   eaptls_process returned 13
>   handler->eap_ds->request->code 1
>   modcall[authenticate]: module "eap" returns handled for request 3
> modcall: group authenticate returns handled for request 3
> Sending Access-Challenge of id 4 to 10.10.10.30:36608
>         EAP-Message = 0x01b8004515800000003b140301000101160301003030e4fdab7d67dceb91c5697db6def4f8eef177f0c0667eb7b2e10b914938020a110b62b9a8c58294fb7167ddcf632198
>         Message-Authenticator = 0x00000000000000000000000000000000
>         State = 0xb05f2612324e0b8f554a931e7aae884f
> Finished request 3
> Going to the next request
> --- Walking the entire request list ---
> Waking up in 5 seconds...
> rad_recv: Access-Request packet from host 10.10.10.30:36608, id=5, length=322
>         Calling-Station-Id = "00-17-C4-27-4E-F6"
>         Message-Authenticator = 0xbd2e299da68c0fce570a7ef495dc2008
>         EAP-Message = 0x02b800a0150017030100201bf58767a5d5d3de9a4ea315b6083fc742131fb6cd02501ac769823319ddd6b517030100707a91d2dc588840ddf0919e765f88b2f51699304770c74123e77c9d93a5737536b3d51a33a9a48db31b1053c063d33810882c8c86892254de58ddd7ebd93ad670f49b84519cef0a85a7a23a8b78d00fe193b6c12ae296a9e7d35a8567bed40b4abdd238830797ab0c4533203a6b3a0cb8
>         Framed-MTU = 3795
>         User-Name = "anonymous at asb.com"
>         NAS-IP-Address = 10.10.10.30
>         State = 0xb05f2612324e0b8f554a931e7aae884f
>         WiMAX-Attr-46 = 0x00111111323200
>         Service-Type = Framed-User
>         WiMAX-Attr-1 = 0x000105312e3202030203030a
>         WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 4
>   modcall[authorize]: module "preprocess" returns ok for request 4
>   modcall[authorize]: module "chap" returns noop for request 4
>   modcall[authorize]: module "mschap" returns noop for request 4
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 4
>   rlm_eap: EAP packet type response id 184 length 160
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 4
>   modcall[authorize]: module "files" returns notfound for request 4
> modcall: group authorize returns updated for request 4
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 4
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
>   eaptls_verify returned 7
>   rlm_eap_tls: Done initial handshake
>   eaptls_process returned 7
>   handler->eap_ds->request->code 0
>   rlm_eap_ttls: Session established.  Proceeding to decode tunneled attributes.
> before BIO_write in eapttls_process,data_len is 154
> after SSL_read in eapttls_process,err is 76
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 4
>   modcall[authorize]: module "preprocess" returns ok for request 4
>   rlm_chap: Setting 'Auth-Type := CHAP'
>   modcall[authorize]: module "chap" returns ok for request 4
>   modcall[authorize]: module "mschap" returns noop for request 4
>     rlm_realm: Looking up realm "asb.com" for User-Name = "myuser44 at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "myuser44"
>     rlm_realm: Proxying request from user myuser44 to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 4
>   rlm_eap: No EAP-Message, not doing EAP
>   modcall[authorize]: module "eap" returns noop for request 4
>     users: Matched entry myuser44 at line 139
>   modcall[authorize]: module "files" returns ok for request 4
> modcall: group authorize returns ok for request 4
>   rad_check_password:  Found Auth-Type CHAP
> auth: type "CHAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group Auth-Type for request 4
>   rlm_chap: login attempt by "myuser44" with CHAP password
>   rlm_chap: Using clear text password mypass at wd for user myuser44 authentication.
>   rlm_chap: chap user myuser44 authenticated succesfully
>   modcall[authenticate]: module "chap" returns ok for request 4
> modcall: group Auth-Type returns ok for request 4
>   TTLS: Got tunneled Access-Accept
>   modcall[authenticate]: module "eap" returns ok for request 4
> modcall: group authenticate returns ok for request 4
> Sending Access-Accept of id 5 to 10.10.10.30:36608
>         Session-Timeout = 3600
>         Termination-Action = RADIUS-Request
>         Service-Flow-Descriptor = 0x000104008302040083040303050304060301070383080384
>         QoS-Descriptor += 0x000103830403020606000f40000c0302
>         QoS-Descriptor += 0x000103840403020606001f40000c0302
>         MS-MPPE-Recv-Key = 0x8a3b613e1d64e0a0336d2e60e2fb0632b6a43cc6b3d5d2b4e5567d1a96192ce4
>         MS-MPPE-Send-Key = 0x6e80df49b3c1508922184f681e1ce50d92c8be285caffd8ade63819b62a39f71
>         EAP-Message = 0x03b80004
>         Message-Authenticator = 0x00000000000000000000000000000000
>         User-Name = "anonymous"
>         State = 0x2c1b82994bd0419cabdcaf1926213bd5
> Finished request 4
> Going to the next request
> Waking up in 5 seconds...
> rad_recv: Accounting-Request packet from host 10.10.10.30:36609, id=1, length=154
>         User-Name = "anonymous at asb.com"
>         NAS-IP-Address = 10.10.10.30
>         Calling-Station-Id = "00-17-C4-27-4E-F6"
>         Acct-Status-Type = Start
>         Acct-Session-Id = "e5f90e4870000000"
>         Framed-IP-Address = 172.25.240.220
>         WiMAX-Attr-46 = 0x00111111323200
>         WiMAX-Attr-25 = 0x0000
>         WiMAX-Attr-22 = 0x0000000001
>         WiMAX-Attr-26 = 0x000083
>         WiMAX-Attr-27 = 0x000000
>   Processing the preacct section of radiusd.conf
> modcall: entering group preacct for request 5
>   modcall[preacct]: module "preprocess" returns noop for request 5
> rlm_acct_unique: WARNING: Attribute NAS-Port was not found in request, unique ID MAY be inconsistent
> rlm_acct_unique: Hashing ',Client-IP-Address = 10.10.10.30,NAS-IP-Address = 10.10.10.30,Acct-Session-Id = "e5f90e4870000000",User-Name = "anonymous at asb.com"'
> rlm_acct_unique: Acct-Unique-Session-ID = "9eb31fd06ccabd09".
>   modcall[preacct]: module "acct_unique" returns ok for request 5
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Accounting realm is LOCAL.
>   modcall[preacct]: module "suffix" returns noop for request 5
>   modcall[preacct]: module "files" returns noop for request 5
> modcall: group preacct returns ok for request 5
>   Processing the accounting section of radiusd.conf
> modcall: entering group accounting for request 5
> radius_xlat:  '/udir/RADIUS-102.INSTALLED//var/log/radius/radacct/10.10.10.30/detail-20080430'
> rlm_detail: /udir/RADIUS-102.INSTALLED//var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /udir/RADIUS-102.INSTALLED//var/log/radius/radacct/10.10.10.30/detail-20080430
>   modcall[accounting]: module "detail" returns ok for request 5
>   modcall[accounting]: module "unix" returns noop for request 5
> radius_xlat:  '/udir/RADIUS-102.INSTALLED//var/log/radius/radutmp'
> radius_xlat:  'anonymous at asb.com'
>   modcall[accounting]: module "radutmp" returns ok for request 5
> modcall: group accounting returns ok for request 5
> Sending Accounting-Response of id 1 to 10.10.10.30:36609
> Finished request 5
> Going to the next request
> --- Walking the entire request list ---
> Cleaning up request 5 ID 1 with timestamp 48186474
> Waking up in 3 seconds...
> --- Walking the entire request list ---
> Cleaning up request 0 ID 1 with timestamp 48186471
> Cleaning up request 1 ID 2 with timestamp 48186471
> Cleaning up request 2 ID 3 with timestamp 48186471
> Waking up in 1 seconds...
> --- Walking the entire request list ---
> Cleaning up request 3 ID 4 with timestamp 48186472
> Cleaning up request 4 ID 5 with timestamp 48186472
> Nothing to do.  Sleeping until we see a request.
>
>
>   
> ------------------------------------------------------------------------
>
> Starting - reading configuration files ...
> reread_config:  reading radiusd.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/proxy.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/clients.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/snmp.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/eap.conf
> Config:   including file: /udir/RADIUS-102.INSTALLED//etc/raddb/sql.conf
>  main: prefix = "/udir/RADIUS-102.INSTALLED/"
>  main: localstatedir = "/udir/RADIUS-102.INSTALLED//var"
>  main: logdir = "/udir/RADIUS-102.INSTALLED//var/log/radius"
>  main: libdir = "/udir/RADIUS-102.INSTALLED//lib"
>  main: radacctdir = "/udir/RADIUS-102.INSTALLED//var/log/radius/radacct"
>  main: hostname_lookups = no
>  main: max_request_time = 30
>  main: cleanup_delay = 5
>  main: max_requests = 1024
>  main: delete_blocked_requests = 0
>  main: port = 0
>  main: allow_core_dumps = no
>  main: log_stripped_names = no
>  main: log_file = "/udir/RADIUS-102.INSTALLED//var/log/radius/radius.log"
>  main: log_auth = no
>  main: log_auth_badpass = no
>  main: log_auth_goodpass = no
>  main: pidfile = "/udir/RADIUS-102.INSTALLED//var/run/radiusd/radiusd.pid"
>  main: user = "(null)"
>  main: group = "(null)"
>  main: usercollide = no
>  main: lower_user = "no"
>  main: lower_pass = "no"
>  main: nospace_user = "no"
>  main: nospace_pass = "no"
>  main: checkrad = "/udir/RADIUS-102.INSTALLED//sbin/checkrad"
>  main: proxy_requests = yes
>  proxy: retry_delay = 5
>  proxy: retry_count = 3
>  proxy: synchronous = no
>  proxy: default_fallback = yes
>  proxy: dead_time = 120
>  proxy: post_proxy_authorize = yes
>  proxy: wake_all_if_all_dead = no
>  security: max_attributes = 200
>  security: reject_delay = 1
>  security: status_server = no
>  main: debug_level = 0
> read_config_files:  reading dictionary
> read_config_files:  reading naslist
> Using deprecated naslist file.  Support for this will go away soon.
> read_config_files:  reading clients
> read_config_files:  reading realms
> radiusd:  entering modules setup
> Module: Library search path is /udir/RADIUS-102.INSTALLED/lib
> Module: Loaded exec 
>  exec: wait = yes
>  exec: program = "(null)"
>  exec: input_pairs = "request"
>  exec: output_pairs = "(null)"
>  exec: packet_type = "(null)"
> rlm_exec: Wait=yes but no output defined. Did you mean output=none?
> Module: Instantiated exec (exec) 
> Module: Loaded expr 
> Module: Instantiated expr (expr) 
> Module: Loaded PAP 
>  pap: encryption_scheme = "crypt"
> Module: Instantiated pap (pap) 
> Module: Loaded CHAP 
> Module: Instantiated chap (chap) 
> Module: Loaded MS-CHAP 
>  mschap: use_mppe = yes
>  mschap: require_encryption = no
>  mschap: require_strong = no
>  mschap: with_ntdomain_hack = no
>  mschap: passwd = "(null)"
>  mschap: authtype = "MS-CHAP"
>  mschap: ntlm_auth = "(null)"
> Module: Instantiated mschap (mschap) 
> Module: Loaded System 
>  unix: cache = no
>  unix: passwd = "(null)"
>  unix: shadow = "(null)"
>  unix: group = "(null)"
>  unix: radwtmp = "/udir/RADIUS-102.INSTALLED//var/log/radius/radwtmp"
>  unix: usegroup = no
>  unix: cache_reload = 600
> Module: Instantiated unix (unix) 
> Module: Loaded eap 
>  eap: default_eap_type = "ttls"
>  eap: timer_expire = 60
>  eap: ignore_unknown_eap_types = no
>  eap: cisco_accounting_username_bug = no
> rlm_eap: Loaded and initialized type md5
>  tls: rsa_key_exchange = no
>  tls: dh_key_exchange = yes
>  tls: rsa_key_length = 512
>  tls: dh_key_length = 512
>  tls: verify_depth = 0
>  tls: CA_path = "(null)"
>  tls: pem_file_type = yes
>  tls: private_key_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/server-key.pem"
>  tls: certificate_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/server.pem"
>  tls: CA_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/ca-cert.pem"
>  tls: private_key_password = "asb#1234"
>  tls: dh_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/dh"
>  tls: random_file = "/udir/RADIUS-102.INSTALLED//etc/raddb/certs/NEW/random"
>  tls: fragment_size = 1024
>  tls: include_length = yes
>  tls: check_crl = yes
>  tls: check_cert_cn = "(null)"
>  tls: session_resume = 1
> rlm_eap: Loaded and initialized type tls
>  ttls: default_eap_type = "mschapv2"
>  ttls: copy_request_to_tunnel = yes
>  ttls: use_tunneled_reply = yes
> rlm_eap: Loaded and initialized type ttls
>  sim: fast_reauth = no
>  sim: success_notification = no
> rlm_eap_sim: fast_reauth = 0
> rlm_eap_sim: success_notification = 0
> rlm_eap: Loaded and initialized type sim
>  mschapv2: with_ntdomain_hack = no
> rlm_eap: Loaded and initialized type mschapv2
> Module: Instantiated eap (eap) 
> Module: Loaded preprocess 
>  preprocess: huntgroups = "/udir/RADIUS-102.INSTALLED//etc/raddb/huntgroups"
>  preprocess: hints = "/udir/RADIUS-102.INSTALLED//etc/raddb/hints"
>  preprocess: with_ascend_hack = no
>  preprocess: ascend_channels_per_line = 23
>  preprocess: with_ntdomain_hack = no
>  preprocess: with_specialix_jetstream_hack = no
>  preprocess: with_cisco_vsa_hack = no
> Module: Instantiated preprocess (preprocess) 
> Module: Loaded realm 
>  realm: format = "suffix"
>  realm: delimiter = "@"
>  realm: ignore_default = no
>  realm: ignore_null = no
> Module: Instantiated realm (suffix) 
> Module: Loaded files 
>  files: usersfile = "/udir/RADIUS-102.INSTALLED//etc/raddb/users"
>  files: acctusersfile = "/udir/RADIUS-102.INSTALLED//etc/raddb/acct_users"
>  files: preproxy_usersfile = "/udir/RADIUS-102.INSTALLED//etc/raddb/preproxy_users"
>  files: compat = "no"
> Module: Instantiated files (files) 
> Module: Loaded Acct-Unique-Session-Id 
>  acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
> Module: Instantiated acct_unique (acct_unique) 
> Module: Loaded detail 
>  detail: detailfile = "/udir/RADIUS-102.INSTALLED//var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
>  detail: detailperm = 384
>  detail: dirperm = 493
>  detail: locking = no
> Module: Instantiated detail (detail) 
> Module: Loaded radutmp 
>  radutmp: filename = "/udir/RADIUS-102.INSTALLED//var/log/radius/radutmp"
>  radutmp: username = "%{User-Name}"
>  radutmp: case_sensitive = yes
>  radutmp: check_with_nas = yes
>  radutmp: perm = 384
>  radutmp: callerid = yes
> Module: Instantiated radutmp (radutmp) 
> Listening on authentication *:1812
> Listening on accounting *:1813
> Listening on proxy *:1814
> Ready to process requests.
> rad_recv: Access-Request packet from host 10.10.10.40:42816, id=1, length=166
> 	Calling-Station-Id = "00-09-03-09-33-00"
> 	Message-Authenticator = 0x5e908d85c85ef22af68eaf73601a3cfc
> 	EAP-Message = 0x02be001601616e6f6e796d6f7573406173622e636f6d
> 	Framed-MTU = 3795
> 	User-Name = "anonymous at asb.com"
> 	NAS-IP-Address = 10.10.10.40
> 	WiMAX-Attr-46 = 0x00111111323200
> 	Service-Type = Framed-User
> 	WiMAX-Attr-1 = 0x000105312e3202030203030a
> 	WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 0
>   modcall[authorize]: module "preprocess" returns ok for request 0
>   modcall[authorize]: module "chap" returns noop for request 0
>   modcall[authorize]: module "mschap" returns noop for request 0
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 0
>   rlm_eap: EAP packet type response id 190 length 22
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 0
>   modcall[authorize]: module "files" returns notfound for request 0
> modcall: group authorize returns updated for request 0
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 0
>   rlm_eap: EAP Identity
> rlm_eap: try to find eap sim reauthentication_id anonymous at asb.com
>   rlm_eap: processing type tls
>   rlm_eap_tls: Initiate
>   rlm_eap_tls: Start returned 1
>   modcall[authenticate]: module "eap" returns handled for request 0
> modcall: group authenticate returns handled for request 0
> Sending Access-Challenge of id 1 to 10.10.10.40:42816
> 	EAP-Message = 0x01bf00061520
> 	Message-Authenticator = 0x00000000000000000000000000000000
> 	State = 0xb94d99886595d401e895ca75a080543d
> Finished request 0
> Going to the next request
> --- Walking the entire request list ---
> Waking up in 6 seconds...
> rad_recv: Access-Request packet from host 10.10.10.40:42816, id=2, length=222
> 	Calling-Station-Id = "00-09-03-09-33-00"
> 	Message-Authenticator = 0x2eeab9d6dd6f4e0c5c14759cfc2ae7e0
> 	EAP-Message = 0x02bf003c150016030100310100002d0301884dc646a52fdd3582d4e9de7a868ef81d7eabd82c706922b81f0fafc3f18cc9000006002f000400050100
> 	Framed-MTU = 3795
> 	User-Name = "anonymous at asb.com"
> 	NAS-IP-Address = 10.10.10.40
> 	State = 0xb94d99886595d401e895ca75a080543d
> 	WiMAX-Attr-46 = 0x00111111323200
> 	Service-Type = Framed-User
> 	WiMAX-Attr-1 = 0x000105312e3202030203030a
> 	WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 1
>   modcall[authorize]: module "preprocess" returns ok for request 1
>   modcall[authorize]: module "chap" returns noop for request 1
>   modcall[authorize]: module "mschap" returns noop for request 1
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 1
>   rlm_eap: EAP packet type response id 191 length 60
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 1
>   modcall[authorize]: module "files" returns notfound for request 1
> modcall: group authorize returns updated for request 1
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 1
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
>   eaptls_verify returned 7 
>   rlm_eap_tls: Done initial handshake
>     (other): before/accept initialization 
>     TLS_accept: before/accept initialization 
>   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0031], ClientHello  
>     TLS_accept: SSLv3 read client hello A 
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello  
>     TLS_accept: SSLv3 write server hello A 
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0438], Certificate  
>     TLS_accept: SSLv3 write certificate A 
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
>     TLS_accept: SSLv3 write server done A 
>     TLS_accept: SSLv3 flush data 
>     TLS_accept:error in SSLv3 read client certificate A 
> In SSL Handshake Phase 
> In SSL Accept mode  
> hit in SSL is 0
>   eaptls_process returned 13 
>   handler->eap_ds->request->code 1
>   modcall[authenticate]: module "eap" returns handled for request 1
> modcall: group authenticate returns handled for request 1
> Sending Access-Challenge of id 2 to 10.10.10.40:42816
> 	EAP-Message = 0x01c0040a15c000000495160301004a020000460301481861f98fc1a6a20286525d67ef340439e9b335f8e48e28e0c5ec1c97a1018d20af96783b23e5416b305cbb59ba09ee6dc174e1b1dc48772a9aca37aa4ac71d98002f0016030104380b000434000431000218308202143082017d020105300d06092a864886f70d01010405003050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b3009060355040313026361301e170d3037313131393038303533305a170d3038313131383038303533305a3055310b3009060355
> 	EAP-Message = 0x040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b13037264723110300e060355040313076173622e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100b0634f379d38220d960a6f7c80abd51a2b7a9cac830613ec665fae7c1ca6215b60ea222142e7c6832c6d344dae7bc5cc3385db768824fbc63c93bfe9c79af932248380799e7f7bbb1ad953ac64adf590f2af0d02a5440e7a67769c92fcb74b4e20cb6776513eb13297599961c1be81ec0c6633ef709da026e96feebe5d0ab5e70203010001300d06092a864886f70d010104
> 	EAP-Message = 0x05000381810069e6b80739a38b06b15a28ace28510b0fc9a26d291c4b9ab9102bc349827197bce7bf4d3bca49e5a5bc61da2b1d9f96e504a469deaf4cf1d915b844f8506ccdd9e995654aafca0e93598b19ab21667ecb40617b4a0e80816a89e3924aeb0c53d93dad0a14e8c678197708ad92f1769673a4499d5ec811a090253bf18df6dd5b50002133082020f30820178020100300d06092a864886f70d01010405003050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b3009060355040313026361301e170d30373131
> 	EAP-Message = 0x31393038303433315a170d3038313131383038303433315a3050310b3009060355040613026368310b3009060355040813027368310b3009060355040713027368310c300a060355040a1303617362310c300a060355040b1303726472310b300906035504031302636130819f300d06092a864886f70d010101050003818d0030818902818100dc70ad4fc5351431abb49e7f58f1d25e90634ea6dcb7f5f440ac2059ccb4d5b47a0c6c1c62014d96c48cb295344fa36bea1dfeb171dab4aa2238087937ac41e513c49af623af2ab3170628cb1d954fdc4587171caae000e325620f5d35aee55712d8f28af71e1be41bed4970bc00c4320a3208bae176
> 	EAP-Message = 0x2d816730040ada827c0d0203010001300d06092a8648
> 	Message-Authenticator = 0x00000000000000000000000000000000
> 	State = 0x1121920b7cafc8ed8f02ce7b32e8ccc6
> Finished request 1
> Going to the next request
> --- Walking the entire request list ---
> Waking up in 5 seconds...
> rad_recv: Access-Request packet from host 10.10.10.40:42816, id=3, length=168
> 	Calling-Station-Id = "00-09-03-09-33-00"
> 	Message-Authenticator = 0x7ee253d0f50fad18eb39e5bb1481c0ba
> 	EAP-Message = 0x02c000061500
> 	Framed-MTU = 3795
> 	User-Name = "anonymous at asb.com"
> 	NAS-IP-Address = 10.10.10.40
> 	State = 0x1121920b7cafc8ed8f02ce7b32e8ccc6
> 	WiMAX-Attr-46 = 0x00111111323200
> 	Service-Type = Framed-User
> 	WiMAX-Attr-1 = 0x000105312e3202030203030a
> 	WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 2
>   modcall[authorize]: module "preprocess" returns ok for request 2
>   modcall[authorize]: module "chap" returns noop for request 2
>   modcall[authorize]: module "mschap" returns noop for request 2
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 2
>   rlm_eap: EAP packet type response id 192 length 6
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 2
>   modcall[authorize]: module "files" returns notfound for request 2
> modcall: group authorize returns updated for request 2
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 2
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
> rlm_eap_tls: Received EAP-TLS ACK message
>   rlm_eap_tls: ack handshake fragment handler
>   eaptls_verify returned 1 
>   eaptls_process returned 13 
>   handler->eap_ds->request->code 1
>   modcall[authenticate]: module "eap" returns handled for request 2
> modcall: group authenticate returns handled for request 2
> Sending Access-Challenge of id 3 to 10.10.10.40:42816
> 	EAP-Message = 0x01c1009f15800000049586f70d010104050003818100321f6dace1aa2f6e55d16f64eb6363393119b3da5c41a7127c7b46e0931d115b6ecb9f52a33868ab8e969dc418740767936cb9f9da02837b868ba824fcad2df8fe3a2fe5cff8dac483603ce312e0218bb93681b208d15fe55ac185416d56696c75d5dd0d8981f3b49962b3b23608fd7010e0ccd32501a7240ec82973066c733216030100040e000000
> 	Message-Authenticator = 0x00000000000000000000000000000000
> 	State = 0x12ebf3597de64d06483805dad5a0bfba
> Finished request 2
> Going to the next request
> Waking up in 5 seconds...
> rad_recv: Access-Request packet from host 10.10.10.40:42816, id=4, length=366
> 	Calling-Station-Id = "00-09-03-09-33-00"
> 	Message-Authenticator = 0x238616ef141ce9d056b206ed8ad49caf
> 	EAP-Message = 0x02c100cc1500160301008610000082008048b405319400ee605ac47c0369529b765dbf4a6ac830f644195739290fc29f00a8625948fad1fdcb2e0061a71ce09166b0b70c972f40b6b45efced578f3224cb9515cc4a025771f55413cd120ab1136327827b71e47fed1e9ab66f9efb909c14ee39767e409fe0b1f2d6cfb501f330f9f8a0912dfbaac92af83bad947ea962cf1403010001011603010030191fde8c20253aac5b4656bb364ca0043bdb23d10cba2b2067bfb15317fbe1cb2228159490f58cb7439000ec2e364fd0
> 	Framed-MTU = 3795
> 	User-Name = "anonymous at asb.com"
> 	NAS-IP-Address = 10.10.10.40
> 	State = 0x12ebf3597de64d06483805dad5a0bfba
> 	WiMAX-Attr-46 = 0x00111111323200
> 	Service-Type = Framed-User
> 	WiMAX-Attr-1 = 0x000105312e3202030203030a
> 	WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 3
>   modcall[authorize]: module "preprocess" returns ok for request 3
>   modcall[authorize]: module "chap" returns noop for request 3
>   modcall[authorize]: module "mschap" returns noop for request 3
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 3
>   rlm_eap: EAP packet type response id 193 length 204
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 3
>   modcall[authorize]: module "files" returns notfound for request 3
> modcall: group authorize returns updated for request 3
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 3
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
>   eaptls_verify returned 7 
>   rlm_eap_tls: Done initial handshake
>   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
>     TLS_accept: SSLv3 read client key exchange A 
>   rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]  
>   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished  
>     TLS_accept: SSLv3 read finished A 
>   rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]  
>     TLS_accept: SSLv3 write change cipher spec A 
>   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished  
>     TLS_accept: SSLv3 write finished A 
>     TLS_accept: SSLv3 flush data 
>     (other): SSL negotiation finished successfully 
> SSL Connection Established 
> sesssion resume success is 0
> hit in SSL is 0
>   eaptls_process returned 13 
>   handler->eap_ds->request->code 1
>   modcall[authenticate]: module "eap" returns handled for request 3
> modcall: group authenticate returns handled for request 3
> Sending Access-Challenge of id 4 to 10.10.10.40:42816
> 	EAP-Message = 0x01c2004515800000003b14030100010116030100302cd0057d22673f11ae3f0427dad4d8cec69ef74eb66a2041821c2df9931fd1de83eb15a2d7ef90cf0a1d1d9196aabd5d
> 	Message-Authenticator = 0x00000000000000000000000000000000
> 	State = 0x9a7e0ea0eff915be514e3cbab99cf088
> Finished request 3
> Going to the next request
> Waking up in 5 seconds...
> rad_recv: Access-Request packet from host 10.10.10.40:42816, id=5, length=317
> 	Calling-Station-Id = "00-09-03-09-33-00"
> 	Message-Authenticator = 0x5aca1dcd2ee1e58926d76a0f6aefda37
> 	EAP-Message = 0x02c2009b150017030100908cadd240a7fc425f2f384cfda16fda6fded6f1c2faec6df6f5b0572b2e71751f17b7f224dd27fdbc11baa7e2c95ce43b4e0f9632b7a20c6ab60afc5e629455b91b6d394c6b3e4baf070b2c46b74d0b22460ba1120843e6dcb803db97cd599dc53c57bfff68b9e8721276f6e7007806968898915ab719621a2838a2e073c944beb9aea3e5579602ffc9fdcd73ab65e03f
> 	Framed-MTU = 3795
> 	User-Name = "anonymous at asb.com"
> 	NAS-IP-Address = 10.10.10.40
> 	State = 0x9a7e0ea0eff915be514e3cbab99cf088
> 	WiMAX-Attr-46 = 0x00111111323200
> 	Service-Type = Framed-User
> 	WiMAX-Attr-1 = 0x000105312e3202030203030a
> 	WiMAX-Attr-36 = 0x0000000001
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 4
>   modcall[authorize]: module "preprocess" returns ok for request 4
>   modcall[authorize]: module "chap" returns noop for request 4
>   modcall[authorize]: module "mschap" returns noop for request 4
>     rlm_realm: Looking up realm "asb.com" for User-Name = "anonymous at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "anonymous"
>     rlm_realm: Proxying request from user anonymous to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 4
>   rlm_eap: EAP packet type response id 194 length 155
>   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
> rlm_eap: try to find eap sim reauthentication_id anonymous
>   modcall[authorize]: module "eap" returns updated for request 4
>   modcall[authorize]: module "files" returns notfound for request 4
> modcall: group authorize returns updated for request 4
>   rad_check_password:  Found Auth-Type EAP
> auth: type "EAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group authenticate for request 4
>   rlm_eap: Request found, released from the list
>   rlm_eap: EAP/ttls
>   rlm_eap: processing type ttls
>   rlm_eap_ttls: Authenticate
>   rlm_eap_tls: processing TLS
>   eaptls_verify returned 7 
>   rlm_eap_tls: Done initial handshake
>   eaptls_process returned 7 
>   handler->eap_ds->request->code 0
>   rlm_eap_ttls: Session established.  Proceeding to decode tunneled attributes.
> before BIO_write in eapttls_process,data_len is 149
> after SSL_read in eapttls_process,err is 116
>   Processing the authorize section of radiusd.conf
> modcall: entering group authorize for request 4
>   modcall[authorize]: module "preprocess" returns ok for request 4
>   modcall[authorize]: module "chap" returns noop for request 4
>   rlm_mschap: Found MS-CHAP attributes.  Setting 'Auth-Type  = MS-CHAP'
>   modcall[authorize]: module "mschap" returns ok for request 4
>     rlm_realm: Looking up realm "asb.com" for User-Name = "myuser44 at asb.com"
>     rlm_realm: Found realm "asb.com"
>     rlm_realm: Adding Stripped-User-Name = "myuser44"
>     rlm_realm: Proxying request from user myuser44 to realm asb.com
>     rlm_realm: Adding Realm = "asb.com"
>     rlm_realm: Authentication realm is LOCAL.
>   modcall[authorize]: module "suffix" returns noop for request 4
>   rlm_eap: No EAP-Message, not doing EAP
>   modcall[authorize]: module "eap" returns noop for request 4
>     users: Matched entry myuser44 at line 139
>   modcall[authorize]: module "files" returns ok for request 4
> modcall: group authorize returns ok for request 4
>   rad_check_password:  Found Auth-Type MS-CHAP
> auth: type "MS-CHAP"
>   Processing the authenticate section of radiusd.conf
> modcall: entering group Auth-Type for request 4
>   rlm_mschap: Told to do MS-CHAPv2 for myuser44 at asb.com with NT-Password
> rlm_mschap: adding MS-CHAPv2 MPPE keys
>   modcall[authenticate]: module "mschap" returns ok for request 4
> modcall: group Auth-Type returns ok for request 4
>   TTLS: Got tunneled Access-Accept
>   modcall[authenticate]: module "eap" returns ok for request 4
> modcall: group authenticate returns ok for request 4
> Sending Access-Accept of id 5 to 10.10.10.40:42816
> 	MS-MPPE-Recv-Key = 0x1da9c1c1e531f3196e83dfc1916b5b3a86b495ab8e2af29713c599be4bdfbbfd
> 	MS-MPPE-Send-Key = 0xe1059cf8c3c43acb40917d40d11f75b38d3ebcdd7ff3c8ce50555cfed46e286b
> 	EAP-Message = 0x03c20004
> 	Message-Authenticator = 0x00000000000000000000000000000000
> 	User-Name = "anonymous"
> 	State = 0x84615d95aae822404e0a3e27f174ea81
> Finished request 4
> Going to the next request
> Waking up in 5 seconds...
> --- Walking the entire request list ---
> Cleaning up request 0 ID 1 with timestamp 481861f8
> Waking up in 1 seconds...
> --- Walking the entire request list ---
> Cleaning up request 1 ID 2 with timestamp 481861f9
> Cleaning up request 2 ID 3 with timestamp 481861f9
> Cleaning up request 3 ID 4 with timestamp 481861f9
> Cleaning up request 4 ID 5 with timestamp 481861f9
> Nothing to do.  Sleeping until we see a request.
>   
> ------------------------------------------------------------------------
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html




More information about the Freeradius-Users mailing list