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