Log says "duplicate requests", CPU maxing out

Chhaya, Harshal hchhaya at ti.com
Wed Mar 11 20:32:24 CET 2009


>  Ok... can you say what platform you are running it on?

It's an ARM running Montevista Linux.

> I'd suspect radutmp and/or radwtmp.  Why are you using those?  
> Do you need them?

Nope. They were around because we didn't know enough to scrub the
config files to remove unused modules. We have now removed references 
to these as well as all sql-related configs from radiusd.conf. 

We also moved out 'pam', 'sql-counter', 'detail.example.com', 
'mac2vlan', 'krb5', 'sradutmp', 'wimax', 'perl' and 'ldap' from 
the 'modules' directory. And modified 'sites-available/inner-tunnel' 
and 'sites-available/default' to remove references to radutmp.

The server seems faster but we still see some 'discarding duplicate 
request from client' messages in radius.log.

The debug output for one such client is below:
(chap/mschap/suffix returns noop. I don't know what that means.)



Going to the next request
Waking up in 2.1 seconds.
rad_recv: Access-Request packet from host 192.168.0.232 port 1418, id=102, lengt
h=296

            Message-Authenticator = 0x6bf2d880bd907dd9b4e327b0ed7aff74
            Service-Type = Framed-User
            User-Name = "000000093701b104"
            Framed-MTU = 1488
            State = 0x86e621af86e7383ccbec5f2181722704
            Called-Station-Id = "001E2AECC893:TI-NAV-N-001E2AECC893"
            Calling-Station-Id = "00093701B104"
            NAS-Identifier = "netgearecc892"
            NAS-Port-Type = Wireless-802.11
            Connect-Info = "CONNECT 54Mbps 802.11g"
            EAP-Message = 0x0201005619800000004c160301004701000043030145994871a26e9f222a077054ef1e14a22356d029fe14610021edf5d98291fb9400001c0016000a0005000400640062006100600015000900140008000600030100
            NAS-IP-Address = 192.168.0.232
            NAS-Port = 14
            NAS-Port-Id = "STA port # 14"
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "000000093701b104", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 86
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 76
[peap] Length Included
[peap] eaptls_verify returned 11 
[peap]     (other): before/accept initialization 
[peap]     TLS_accept: before/accept initialization 
[peap] <<< TLS 1.0 Handshake [length 0047], ClientHello  
[peap]     TLS_accept: SSLv3 read client hello A 
[peap] >>> TLS 1.0 Handshake [length 002a], ServerHello  
[peap]     TLS_accept: SSLv3 write server hello A 
[peap] >>> TLS 1.0 Handshake [length 085e], Certificate  
[peap]     TLS_accept: SSLv3 write certificate A 
[peap] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange  
[peap]     TLS_accept: SSLv3 write key exchange A 
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
[peap]     TLS_accept: SSLv3 write server done A 
[peap]     TLS_accept: SSLv3 flush data 
[peap]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 102 to 192.168.0.232 port 1418
            EAP-Message = 0x0102040019c000000aad160301002a02000026030100000aed4888c1cff2bdb0da7542f34c31902d463f1d1eeee7d047dfe83cdefd00001600160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479 
            EAP-Message = 0x301e170d3039303330333135343031345a170d3130303330333135343031345a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100d594ca11035bb697ac3bea14f92ef0d99be18c91ece91b91b45f5c808d085b8aad053689568a31467824ce7780f857cb73d6f5135aa168909bef37632bfe
            EAP-Message = 0x122f1f84f886b92c864182ced13b7d6fe4954296e852df73db3a8993a2618bbc260154dd5940a3f8912843096b34afddff1458836918077190a78c5541fe624617140bdb41bfc66bd954521b3409fbabcbd74b26725daa8d9d82e6a3e28c617933a11f11fcdf3c49436a56aa9d6ef8fe7d8bb867c8d577520219558210c3e9bff4555dc6896f61e94fc404fa7287ebf7a128f969ac55a7b7ce3787e00ce21d7f718f4dffa93f60e0713f9ef723500f0c40bafb6bf23f236ea091479847914917d0130203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010405000382010100764f73fbf1e2cddfcc
            EAP-Message = 0x284b9fea1ba135c65946f4e7a4ec44e45e8f3d16870048a1a55567ab5bf083fbd6d16a929ed4489238e24ecb66d97dbfa24998c1b661f68cb16f980cbccbc67984e6b807324fba5eee16a319d60390010c8259643b439fcc50c9fb30557c543b5633ee860777d8d3a0ba8a7f37010eaa7004e1e2257f7d028da6dc0adbd855586e6a4b2c0323e1df6337674a842e40c49eb01a77a13fc0eeda2687ba5beed8f093ba7e80f63376326737399ff4d28d18e56ccb42744ca8613e094bf56dc4d1a6a0de185928083aed0cd26da2f69d715da11a3d548794411efa1333dc5db9ae1e69208a357fefb7f79fa7cc959166e00efbb153eedf2cf70004ab308204
            EAP-Message = 0xa73082038fa0030201020209
            Message-Authenticator = 0x00000000000000000000000000000000
            State = 0x86e621af87e4383ccbec5f2181722704
Finished request 10.
Going to the next request
Waking up in 0.7 seconds.
rad_recv: Access-Request packet from host 192.168.0.232 port 1418, id=102, length=296 
Sending duplicate reply to client test-net port 1418 - ID: 102
Sending Access-Challenge of id 102 to 192.168.0.232 port 1418
Waking up in 0.7 seconds.
rad_recv: Access-Request packet from host 192.168.0.232 port 1418, id=103, length=216

            Message-Authenticator = 0xdfb75fac30c3d5eef250a17ce0bdb188
            Service-Type = Framed-User
            User-Name = "000000093701b104"
            Framed-MTU = 1488
            State = 0x86e621af87e4383ccbec5f2181722704
            Called-Station-Id = "001E2AECC893:TI-NAV-N-001E2AECC893"
            Calling-Station-Id = "00093701B104"
            NAS-Identifier = "netgearecc892"
            NAS-Port-Type = Wireless-802.11
            Connect-Info = "CONNECT 54Mbps 802.11g"
            EAP-Message = 0x020200061900
            NAS-IP-Address = 192.168.0.232
            NAS-Port = 14
            NAS-Port-Id = "STA port # 14"
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "000000093701b104", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1 
[peap] eaptls_process returned 13 
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 103 to 192.168.0.232 port 1418
            EAP-Message = 0x010303fc194000feada2bc5177f382300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3039303330333135343031345a170d3130303330333135343031345a308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504
            EAP-Message = 0x071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100aff59b69f34f27a8922dd9474ccc00464f6d58db2e7cac620ede571d8f6bc87504156ee3ae44ddec37da512a67950fb70ec432f538d0c00a2694e266861ce097c968d1ab555ae9689f59e304311db4e5cb6f13574a56a7e20e4c624cf3b957bcb79f5b8b9e3bebd646cad0dd275bd6
            EAP-Message = 0x70a4940f6ba964a7bc491065ecd81a0929c3590ef7c6f9dab1c323d72390bc63525b87e0b836874dd651c9df7619ae66d89547b080b8f435f512685a1c2aef6b1d18a35a3b46be61b89c22bed59c19549b5f3988b4d3c563767006775fdfca936ad2275767b0360e2a49d774b6bdf90ed8f53c8938d337c2f1614007c8a427d36ebf6ebbaa99551bd49b534bc4c165eacd0203010001a381fb3081f8301d0603551d0e04160414ec834741fc51f4a46b42740ec8f8aea3804c85a83081c80603551d230481c03081bd8014ec834741fc51f4a46b42740ec8f8aea3804c85a8a18199a48196308193310b3009060355040613024652310f300d06035504
            EAP-Message = 0x0813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900feada2bc5177f382300c0603551d13040530030101ff300d06092a864886f70d010105050003820101008fb06746b5666f0c1d9e1da543a84973a01b5ef2a29b7ef92bd02c05867c980f61f7190422dc5f9428a3a03e1f56d06b339aca8940085e2de47976a248d74b210dc9ab686f7fe6e3fdad450f47a151555c4c
            EAP-Message = 0xef2dd79b865e6630
            Message-Authenticator = 0x00000000000000000000000000000000
            State = 0x86e621af84e5383ccbec5f2181722704
Finished request 11.
Going to the next request
Waking up in 0.3 seconds.
rad_recv: Access-Request packet from host 192.168.0.232 port 1418, id=104, length=216


Thanks,
- Harshal




More information about the Freeradius-Users mailing list