Freeradius is not restarting properly (fails to quit and becomes a zombie process)

Jason Wittlin-Cohen jasonwc at brandeis.edu
Fri Sep 29 04:42:59 CEST 2006


select(5, [3 4], NULL, NULL, {6, 0})    = 1 (in [3], left {5, 992000})
time(NULL)                              = 1159497421
recvfrom(3, "\1\1\0\227\247\326\245\\\207\222(\352H\305\311\213\300"...,
4096, 0, {sa_family=AF_INET, sin_port=htons(2054),
sin_addr=inet_addr("192.168.0.1")}, [16]) = 151
write(1, "rad_recv: Access-Request packet "..., 77rad_recv:
Access-Request packet from host 192.168.0.1:2054, id=1, length=151
) = 77
time(NULL)                              = 1159497421
write(1, "\tUser-Name = \"Jason Wittlin-Cohe"..., 35    User-Name =
"Jason Wittlin-Cohen"
) = 35
write(1, "\tNAS-IP-Address = 192.168.0.1\n", 30 NAS-IP-Address = 192.168.0.1
) = 30
write(1, "\tCalled-Station-Id = \"00160112eb"..., 36   
Called-Station-Id = "00160112ebda"
) = 36
write(1, "\tCalling-Station-Id = \"00095b934"..., 37   
Calling-Station-Id = "00095b93459e"
) = 37
write(1, "\tNAS-Identifier = \"00160112ebda\""..., 33   NAS-Identifier =
"00160112ebda"
) = 33
write(1, "\tNAS-Port = 8\n", 14 NAS-Port = 8
)        = 14
write(1, "\tFramed-MTU = 1400\n", 19    Framed-MTU = 1400
)   = 19
write(1, "\tState = 0x8570d74429dcf8507949a"..., 44     State =
0x8570d74429dcf8507949ae638bd52940
) = 44
write(1, "\tNAS-Port-Type = Wireless-802.11"..., 33     NAS-Port-Type =
Wireless-802.11
) = 33
write(1, "\tEAP-Message = 0x020800060d00\n", 30 EAP-Message = 0x020800060d00
) = 30
write(1, "\tMessage-Authenticator = 0xb781d"..., 60    
Message-Authenticator = 0xb781dd8563450fa51bff3ce9be35dac3
) = 60
time(NULL)                              = 1159497421
write(1, "  Processing the authorize secti"..., 51  Processing the
authorize section of radiusd.conf
) = 51
time(NULL)                              = 1159497421
write(1, "modcall: entering group authoriz"..., 48modcall: entering
group authorize for request 8
) = 48
time(NULL)                              = 1159497421
write(1, "  modcall[authorize]: module \"pr"..., 67  modcall[authorize]:
module "preprocess" returns ok for request 8
) = 67
time(NULL)                              = 1159497421
write(1, "  modcall[authorize]: module \"ch"..., 63  modcall[authorize]:
module "chap" returns noop for request 8
) = 63
time(NULL)                              = 1159497421
write(1, "  modcall[authorize]: module \"ms"..., 65  modcall[authorize]:
module "mschap" returns noop for request 8
) = 65
time(NULL)                              = 1159497421
write(1, "    rlm_realm: No \'@\' in User-Na"..., 82    rlm_realm: No
'@' in User-Name = "Jason Wittlin-Cohen", looking up realm NULL
) = 82
time(NULL)                              = 1159497421
time(NULL)                              = 1159497421
write(1, "    rlm_realm: No such realm \"NU"..., 36    rlm_realm: No
such realm "NULL"
) = 36
time(NULL)                              = 1159497421
write(1, "  modcall[authorize]: module \"su"..., 65  modcall[authorize]:
module "suffix" returns noop for request 8
) = 65
time(NULL)                              = 1159497421
write(1, "  rlm_eap: EAP packet type respo"..., 50  rlm_eap: EAP packet
type response id 8 length 6
) = 50
time(NULL)                              = 1159497421
write(1, "  rlm_eap: No EAP Start, assumin"..., 68  rlm_eap: No EAP
Start, assuming it's an on-going EAP conversation
) = 68
time(NULL)                              = 1159497421
write(1, "  modcall[authorize]: module \"ea"..., 65  modcall[authorize]:
module "eap" returns updated for request 8
) = 65
time(NULL)                              = 1159497421
write(1, "    users: Matched entry Jason W"..., 56    users: Matched
entry Jason Wittlin-Cohen at line 96
) = 56
time(NULL)                              = 1159497421
write(1, "  modcall[authorize]: module \"fi"..., 62  modcall[authorize]:
module "files" returns ok for request 8
) = 62
time(NULL)                              = 1159497421
write(1, "modcall: leaving group authorize"..., 65modcall: leaving group
authorize (returns updated) for request 8
) = 65
time(NULL)                              = 1159497421
write(1, "  rad_check_password:  Found Aut"..., 43  rad_check_password: 
Found Auth-Type EAP
) = 43
time(NULL)                              = 1159497421
write(1, "auth: type \"EAP\"\n", 17auth: type "EAP"
)    = 17
time(NULL)                              = 1159497421
write(1, "  Processing the authenticate se"..., 54  Processing the
authenticate section of radiusd.conf
) = 54
time(NULL)                              = 1159497421
write(1, "modcall: entering group authenti"..., 51modcall: entering
group authenticate for request 8
) = 51
time(NULL)                              = 1159497421
write(1, "  rlm_eap: Request found, releas"..., 49  rlm_eap: Request
found, released from the list
) = 49
time(NULL)                              = 1159497421
write(1, "  rlm_eap: EAP/tls\n", 19  rlm_eap: EAP/tls
)    = 19
time(NULL)                              = 1159497421
write(1, "  rlm_eap: processing type tls\n", 31  rlm_eap: processing
type tls
) = 31
time(NULL)                              = 1159497421
write(1, "  rlm_eap_tls: Authenticate\n", 28  rlm_eap_tls: Authenticate
) = 28
time(NULL)                              = 1159497421
write(1, "  rlm_eap_tls: processing TLS\n", 30  rlm_eap_tls: processing TLS
) = 30
time(NULL)                              = 1159497421
write(1, "rlm_eap_tls: Received EAP-TLS AC"..., 42rlm_eap_tls: Received
EAP-TLS ACK message
) = 42
time(NULL)                              = 1159497421
write(1, "  rlm_eap_tls: ack handshake is "..., 41  rlm_eap_tls: ack
handshake is finished
) = 41
time(NULL)                              = 1159497421
write(1, "  eaptls_verify returned 3 \n", 28  eaptls_verify returned 3
) = 28
time(NULL)                              = 1159497421
write(1, "  eaptls_process returned 3 \n", 29  eaptls_process returned 3
) = 29
time(NULL)                              = 1159497421
write(1, "  rlm_eap: Freeing handler\n", 27  rlm_eap: Freeing handler
) = 27
time(NULL)                              = 1159497421
write(1, "  modcall[authenticate]: module "..., 63 
modcall[authenticate]: module "eap" returns ok for request 8
) = 63
time(NULL)                              = 1159497421
write(1, "modcall: leaving group authentic"..., 63modcall: leaving group
authenticate (returns ok) for request 8
) = 63
time(NULL)                              = 1159497421
write(1, "Login OK: [Jason Wittlin-Cohen] "..., 75Login OK: [Jason
Wittlin-Cohen] (from client WLAN port 8 cli 00095b93459e)
) = 75
write(1, "Sending Access-Accept of id 1 to"..., 55Sending Access-Accept
of id 1 to 192.168.0.1 port 2054
) = 55
write(1, "\tMS-MPPE-Recv-Key = 0xf4b929a28e"..., 87     MS-MPPE-Recv-Key
= 0xf4b929a28edd544381b7df6e67e298627f682b0b4a01e9de61a113c3a14176d2
) = 87
write(1, "\tMS-MPPE-Send-Key = 0xfed62e9031"..., 87     MS-MPPE-Send-Key
= 0xfed62e90314b182ecaf572ce6ee6993aa39927c7610c1644204fef340f748862
) = 87
write(1, "\tEAP-Message = 0x03080004\n", 26     EAP-Message = 0x03080004
) = 26
write(1, "\tMessage-Authenticator = 0x00000"..., 60    
Message-Authenticator = 0x00000000000000000000000000000000
) = 60
write(1, "\tUser-Name = \"Jason Wittlin-Cohe"..., 35    User-Name =
"Jason Wittlin-Cohen"
) = 35
sendto(3, "\2\1\0\265\265\351Rn\0015F\300\0\224Nr\354\340\36\316\32"...,
181, 0, {sa_family=AF_INET, sin_port=htons(2054),
sin_addr=inet_addr("192.168.0.1")}, 16) = 181
time(NULL)                              = 1159497421
write(1, "Finished request 8\n", 19Finished request 8
)    = 19
time(NULL)                              = 1159497421
write(1, "Going to the next request\n", 26Going to the next request
) = 26
time(NULL)                              = 1159497421
write(1, "Waking up in 6 seconds...\n", 26Waking up in 6 seconds...
) = 26
select(5, [3 4], NULL, NULL, {6, 0})    = 0 (Timeout)
time(NULL)                              = 1159497427
time(NULL)                              = 1159497427
write(1, "--- Walking the entire request l"..., 40--- Walking the entire
request list ---
) = 40
time(NULL)                              = 1159497427
write(1, "Cleaning up request 8 ID 1 with "..., 51Cleaning up request 8
ID 1 with timestamp 451c86cd
) = 51
time(NULL)                              = 1159497427
write(1, "Nothing to do.  Sleeping until w"..., 49Nothing to do. 
Sleeping until we see a request.
) = 49
select(5, [3 4], NULL, NULL, NULL)      = ? ERESTARTNOHAND (To be restarted)
--- SIGTERM (Terminated) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
time(NULL)                              = 1159497505
time(NULL)                              = 1159497505
write(1, "--- Walking the entire request l"..., 40--- Walking the entire
request list ---
) = 40
time(NULL)                              = 1159497505
write(1, "Nothing to do.  Sleeping until w"..., 49Nothing to do. 
Sleeping until we see a request.
) = 49
time(NULL)                              = 1159497505
write(1, "Exiting...\n", 11Exiting...
)            = 11
rt_sigaction(SIGTERM, {SIG_IGN}, {0x80593e0, [], 0}, 8) = 0
kill(-25503, SIGTERM)                   = -1 ESRCH (No such process)
munmap(0xb7dce000, 9144)                = 0
munmap(0xb7dad000, 8940)                = 0
--- SIGTERM (Terminated) @ 0 (0) ---
+++ killed by SIGKILL +++

I started the server with "strace radiusd -X" and authenticated a
client. I then tried to kill the process with "kill 25503" which showed
the output:

) = 49
time(NULL)                              = 1159497505
write(1, "Exiting...\n", 11Exiting...
)            = 11
rt_sigaction(SIGTERM, {SIG_IGN}, {0x80593e0, [], 0}, 8) = 0
kill(-25503, SIGTERM)                   = -1 ESRCH (No such process)
munmap(0xb7dce000, 9144)                = 0
munmap(0xb7dad000, 8940)                = 0

When I used "kill -9 25503" it ended successfully:

--- SIGTERM (Terminated) @ 0 (0) ---
+++ killed by SIGKILL +++

James Wakefield wrote:
> Jason Wittlin-Cohen wrote:
>> Over the last few days I've been having a recurring problem. Whenever I
>> start Freeradius either with radiusd in a terminal or as a service in
>> Debian, I can not restart/kill radiusd properly if it's authenticated
>> any clients. Restarting the service says it's successful but the radius
>> log states that port 1812 is already in use. "top" shows 100% cpu usage
>> after I attempt to restart radiusd. In addition, kill will not work. I
>> need to use kill -9. No errors are thrown when I try to kill it in debug
>> mode either. It just says exiting and sits there but doesn't die.
>
> Howdy Jason,
>
> Might you get any useful info by running radiusd with strace?
>
> Cheers,
>



More information about the Freeradius-Users mailing list