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,