On Tuesday, October 16, 2012 5:43:28 AM UTC+2, J wrote: > Hi... > > > > I have a bit of code that does the following: > > > > uses the syslog module to inject a LOG_INFO message into the syslog on > > my linux machine > > runs a suspend/resume cycle > > uses the syslog module to inkect a LOG_INFO message marking the end of test. > > > > Then I parse everything between the start and stop markers for certain > > items that the Linux kernel logs during a suspend and resume cycle. > > > > But my "resume complete" timing is not as accurate as it could be. > > The problem with doing it this way is that while I can find definite > > kernel messages that mark various points in the suspend/resume cycle, > > the final message when the kernel is done resuming is NOT the point I > > actually want to mark. > > > > Instead, the end point I want is the time of the ending marker itself, > > as this happens after certain other things are done such as resumption > > of networking services. > > > > Here's the problem. I can't just use syslog timestamps. The reason > > is that the syslog timestamps are only indicative of when messages are > > written to syslog via syslogd. The kernel timestamps are different. > > For example, the following bits of log are taken from the time the > > test starts until the end of the "going to sleep" kernel messages. > > First, note that there's a 5 second difference between the START > > marker and the first kernel message. Next, look at the kernel > > timestamps. The total real time to suspend starts at 421320.380947 > > and ends at 421322.386355, around 2 seconds later, where the log > > messages themselves all state that the events occurred at the same > > time. > > > > Oct 15 10:24:19 klaatu sleep_test: ---SLEEP TEST START 1350296656--- > > Oct 15 10:25:24 klaatu kernel: [421320.380947] PM: Syncing filesystems ... > done. > > Oct 15 10:25:24 klaatu kernel: [421320.391282] PM: Preparing system > > for mem sleep > > [SNIP] > > Oct 15 10:25:24 klaatu kernel: [421322.282943] Broke affinity for irq 23 > > Oct 15 10:25:24 klaatu kernel: [421322.386355] CPU 7 is now offline > > > > So, what I REALLY want is to inject my start/stop markers into klogd > > rather than syslogd. This will, I hope, give my markers kernel > > timestamps rather than syslog timestamps which are not as accurate. > > > > So does anyone know of a way to do this? Unfortunately, I've tried > > some searching but google doesn't like the term klog, and most of the > > hits involved injecting code or other things that are not related at > > all. > > > > Or, if there's a better way to get accurate timestamps, what would that be?
Hi, I cannot be of too much help here, but is there a userspace/kernel C-interface that could be used. If so, you might be able to use the Python ctypes module to create messages at the correct moments Regards, Marco -- http://mail.python.org/mailman/listinfo/python-list
