so, I run radiusd -Xx under strace... and it looks like I caught the event... not sure what to make of strace though : This is from the radiusd log: Mon Jul 27 21:54:39 2015 : Debug: (31451) } # Post-Auth-Type REJECT = updated Mon Jul 27 21:54:39 2015 : Debug: (31451) Sent Access-Reject Id 250 from 10.212.11.14:1812 to 10.128.254.52:32770 length 0 *Mon Jul 27 21:54:39 2015 :* Debug: (31451) Finished request *Mon Jul 27 21:55:09 2015 :* Debug: PING: Zombie period is over for home server eduroam1 Mon Jul 27 21:55:09 2015 : Proxy: Marking home server 64.57.22.74 port 1812 as dead. Mon Jul 27 21:55:09 2015 : Debug: PING: Reviving home server eduroam1 in 300 seconds Mon Jul 27 21:55:09 2015 : Debug: (31664) <done>: Cleaning up request packet ID 71 with timestamp +4030 Mon Jul 27 21:55:09 2015 : Debug: (31665) <done>: Cleaning up request packet ID 72 with timestamp +4030 Mon Jul 27 21:55:09 2015 : Debug: (31666) <done>: Cleaning up request packet ID 73 with timestamp +4030 Mon Jul 27 21:55:09 2015 : Debug: (31667) <done>: Cleaning up request packet ID 74 with timestamp +4030 Mon Jul 27 21:55:09 2015 : Debug: (31759) <delay>: Sending delayed response Mon Jul 27 21:55:09 2015 : Debug: (31759) <delay>: Sent Access-Reject Id 208 from 10.212.11.14:1812 to 10.128.254.50:32770 length 20 and this from the strace: 21:54:39.637272 write(3, "Mon Jul 27 21:54:39 2015 : Debug"..., 64) = 64 21:54:39.637307 write(3, "Mon Jul 27 21:54:39 2015 : Debug"..., 64) = 64 21:54:39.637343 write(3, "Mon Jul 27 21:54:39 2015 : Debug"..., 92) = 92 21:54:39.637379 write(3, "Mon Jul 27 21:54:39 2015 : Debug"..., 80) = 80 21:54:39.637426 write(3, "Mon Jul 27 21:54:39 2015 : Debug"..., 123) = 123 21:54:39.637476 sendmsg(26, {msg_name(16)={sa_family=AF_INET, sin_port=htons(32770), sin_addr=inet_addr("10.128.254.52")}, msg_iov(1)=[{"\3\372\0\24\331\36sKR)\216\23?\263.\17\356#pR", 20}], msg_controllen=32, {cmsg_len=28, cmsg_level=SOL_IP, cmsg_type=, ...}, msg_flags=0}, 0) = 20 21:54:39.637593 write(3, "Mon Jul 27 21:54:39 2015 : Debug"..., 59) = 59 *21:54:39.637630 *wait4(-1, NULL, WNOHANG, NULL) = -1 ECHILD (No child processes) *21:55:09.500134* write(3, "Mon Jul 27 21:55:09 2015 : Debug"..., 87) = 87 21:55:09.500311 write(3, "Mon Jul 27 21:55:09 2015 : Proxy"..., 85) = 85 21:55:09.500369 write(3, "Mon Jul 27 21:55:09 2015 : Debug"..., 85) = 85 21:55:09.500431 write(3, "Mon Jul 27 21:55:09 2015 : Debug"..., 104) = 104 and it does look like each time this "freeze" happens, it takes exactly 30 seconds? Thanks, Mohamed. On Sun, Jul 26, 2015 at 6:57 PM, Mohamed Lrhazi < Mohamed.Lrhazi@georgetown.edu> wrote:
PsPageFaults spikes for radiusd process, coinciding with the issue.
On Sun, Jul 26, 2015 at 6:52 PM, Mohamed Lrhazi < Mohamed.Lrhazi@georgetown.edu> wrote:
I installed collected on this system, and the one metric that seems to spike at the same time as the issue, is PsPageFaults for radiusd process.
On Sun, Jul 26, 2015 at 6:41 PM, Mohamed Lrhazi < Mohamed.Lrhazi@georgetown.edu> wrote:
Oh, Alan. B suggested strace... I'll see how I can grab that... I am sure I could not possibly run radiusd under tracing the whole time right?
On Sun, Jul 26, 2015 at 6:36 PM, Mohamed Lrhazi < Mohamed.Lrhazi@georgetown.edu> wrote:
I can observe this while running in -Xx mode (via a bash script that
kills it evey 1 minute, and starts it anew, also starts annd stops tcpdump captures)
No, every 3600 seconds, actually. Sorry.