So I've been working with this issue for some time now, and I'm having trouble finding the tools to troubleshoot this problem, which I have to imagine exist. So here's the basics of my problem:
- We run a 4-core RHEL5/centos5 with the preempt-rt patch, and we try to do some things to guarantee that a small number of applications get reasonable determinism (fifo scheduling, high-ish priority, etc). Anyway, we recently started running a PTPv2 client, with a priority just above the default. Well, it turns out that you can actually cause some pretty gruesome side effects if you starve the PTPv2 client of CPU time. Without getting too into the details, it turns out that we're pretty sure that something is hogging the CPU which we've bounded the PTP daemon to, for a relatively short time (since our traditional logging isnt catching it). So the short version is, we start this PTP client in userland (using the
daemoncall), bind it to a specific CPU with
taskset, and let it go. Once every few hours or so, something will either pre-empt our PTP client, or for some reason or another, keep it from running, for some time on the order of 10ms-500ms.
Since I know what CPU PTP is running on, I thought it would be relatively easy to track what is going on with that CPU. Unfortunately, it turns out that while it is very easy to track what is going on with a certain CPU at a given time (top and friends), or an aggregate of some recent time (sar and friends), but it is surprisingly hard to catch spikes of performance that may only last a short period of time (in the millisecond range), but not often (every few hours or so). I've tried the following (but I don't claim to have used them all correctly! so please let me know if you think I've used the correct tool incorrectly):
htop/top: top and friends has been very useful for me to get an overview of what is happening right now. On a multi-core system, this becomes slightly more difficult, as now you have to look at the option which tells you which CPU a process has last executed on, and kind of disregard the rest, but if something happened a while ago, and/or only for a short period of time, it seems to be difficult to get top to do what I want, short of doing a lot of top logging, very often. Htop, while much more pleasing to the eye, seems to offer more or less the same functionality, at least for what I'm trying to do.
sar: sar seemed like it would be better suited, since it supposedly tracks activity over time. However, sar seems to be pretty good at telling you how a system was performing 5, 10, 15 minutes ago, but not why it was performing that way. In other words, it's hard to figure out what process (if it's even a user "process"), that's causing my problem. And either way, I'm looking at logging and parsing lots of data by hand.
mpstat: mpstat is really nice because you can very easily limit what you're looking at to only the CPU you're curious about. However, the information it gives you is pretty opaque, and even if I setup mpstat to run basically constantly (to catch relatively fast events), and even if I manager to see a spike in activity, there isn't much of a way to tell where it came from (unless I'm missing something, in which case, that's why I'm here!).
So, how would you go about solving this problem? I know my userland PTP daemon is getting screwed up because at a basic level, as I understand it, it gets the absolute time from the network, and PTP tries to skew the clock frequency and tick to get closer to that time. However, if for some reason (like PTP gets starved/doesn't run for a while), and the difference it sees between its current time and what it thinks the master time is is quite large (usually > 1s), it just goes ahead and sets/forces the clock without skewing it, which really messes up applications who don't expect the clock to change drastically (in this case drastically is anything more than ~200ms, but we really see things fall apart when the clock shifts immediately by a half second or more)...and this is exactly what I'm seeing. As I said, we taskset it to a CPU, so I know what CPU it is running on. We isolcpus in our grub.conf, and also change the affinity of init so that child processes that init spawns are spawned in a specific (different) CPU, so in theory we have total control over the CPU PTP is running in...but something is still keeping PTP from picking up packets when it should, and I've been pulling my hair out trying to track it.
For the record, yes I do know that we probably should be running PTP as a kernel module, and I have been able to avoid this problem by chrt'ing the PTP daemon to FIFO with a high (low) priority, and that does seem to resolve the issue, but this is more of a general question about tracking system performance on a specific CPU, over time. How would you guys go about tackling such an issue?
Thanks a lot! Any help is super appreciated.