Path: csiph.com!usenet.pasdenom.info!gegeweb.org!de-l.enfer-du-nord.net!feeder1.enfer-du-nord.net!feeds.phibee-telecom.net!newsfeed.xs4all.nl!newsfeed6.news.xs4all.nl!xs4all!newsgate.cistron.nl!newsgate.news.xs4all.nl!post.news.xs4all.nl!not-for-mail
Newsgroups: comp.lang.python
Date: Tue, 16 Oct 2012 03:26:00 -0700 (PDT)
In-Reply-To: <mailman.2248.1350359007.27098.python-list@python.org>
Complaints-To: groups-abuse@google.com
Injection-Info: glegroupsg2000goo.googlegroups.com; posting-host=137.17.109.98; posting-account=QNsEXgoAAABu_Avbf026MEK8WO7y27Mt
References: <mailman.2248.1350359007.27098.python-list@python.org>
User-Agent: G2/1.0
MIME-Version: 1.0
Subject: Re: Is there a way to create kernel log messages via Python?
From: Marco Nawijn <nawijn@gmail.com>
To: comp.lang.python@googlegroups.com
Content-Type: text/plain; charset=ISO-8859-1
Cc: Python List <python-list@python.org>
Precedence: list
Message-ID: <mailman.2261.1350383164.27098.python-list@python.org>
Lines: 111
NNTP-Posting-Host: 2001:888:2000:d::a6
Xref: csiph.com comp.lang.python:31381

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