How do klogd and syslogd influence code execution timing?

How do klogd and syslogd influence code execution timing?

[Konstantin Kletschke]

Hi there!

At the moment me and my colleauge are trying to debug a very bizarre
problem that our usb host controller has (or we :)).
We are implementing a device driver for the usb host controller philips
isp1161a1. We are at the state, that it recognizes usb-storage devices
and we can mount them. But only sometimes.
It is absolutely _required_ that we start syslogd and klogd before
inserting the storage device. Then it gets recognized cleanly. If we
remove or add a printk in some areas of the code, the device recognition
gets sloppy or breaks.
Hardware timing you may point out.

We have the chip connected to an Motorola i.MX cpu (arm9).

I triple checked scratching a 16Bit register and a 32Bit register and
not one bit is misread or miswritten. Not one... There where ndelays in
the code. Together with a scope I adjusted the hardware timing of the
bus signals exactly as the are required by the datasheet. As a result I
removed any ndelays out of the code and scratching, reading and writing
registers works 100%. I am sure. Or what else can I do to test this?
Currently i have to loops from 0 to 0xffff resp 0xffffffff where the
loopcount is written, read back and BUG_ON(1) if written != read.

Now the misterious syslogd/klogd. I think there is an area in the
driver, where we should take care of protecting ourself from the kernel
interfering and doing something. My question to experienced kernel
programmers is, how can we find such an area? Whow are running
syslogd/klogd affecting the "workflow" of the kernel? Or has somebody
experienced a similair situation and the fix is a standerd procedure to
take care of we missed?

Well, kinda weird. it is also not possible to replace syslogd/klogd by
other RAM eating or process time eating server daemons. I tried sshd ir
httpd and stuff. Even replacing the klogd triggering printk by stock
printk does not the same as the logdaemons.

Regards, Konstantin



-- 
GPG KeyID EF62FCEF
Fingerprint: 13C9 B16B 9844 EC15 CC2E  A080 1E69 3FDA EF62 FCEF

Re: How do klogd and syslogd influence code execution timing?

[Andrew Morton]

Konstantin Kletschke <lists@ku-gbr.de> wrote:
>
> It is absolutely _required_ that we start syslogd and klogd before
> inserting the storage device.

The difference is that if klogd is running, a printk() will cause a wakeup
to be delivered to klogd in release_console_sem().  That will cause the CPU
to go into the scheduler code, take and release locks, take more time, etc.

Re: How do klogd and syslogd influence code execution timing?

[Konstantin Kletschke]

Am 2004-12-10 16:26 -0800 schrieb Andrew Morton:
> 
> The difference is that if klogd is running, a printk() will cause a wakeup

Hm, good that I asked. I know now, the difference is the _running_
klogd...

> to go into the scheduler code, take and release locks, take more time, etc.

scheduler code... take/release locks... I think that works around a Bug
or problem we have in our driver code...
But I will have to search for it since I am a greenhorn in writing
device drivers and locking/protecting critical sections :)

Regards, Konsti

-- 
GPG KeyID EF62FCEF
Fingerprint: 13C9 B16B 9844 EC15 CC2E  A080 1E69 3FDA EF62 FCEF