Re: Linux v2.6.18-rc1: printk delays

[john stultz <johnstul@us.ibm.com>]

On Fri, 2006-07-07 at 01:00 +0200, Tilman Schmidt wrote:
> With kernel 2.6.18-rc1 I am experiencing strange delays before printk
> messages from my driver appear in the syslog. The last couple of printk
> lines only appear if I hit a key on the system keyboard. Even just
> pressing and releasing a shift key will do. Other input, like connecting
> with ssh from another computer and typing into that session or moving or
> clicking the mouse, doesn't help. At the same time, userspace syslog
> messages like those from sshd appear just fine.
> 
> Example excerpt from /var/log/messages:
> 
> > Jul  7 00:16:08 gx110 kernel: [  746.583136] gigaset: 0: if_write()
> > Jul  7 00:16:08 gx110 kernel: [  746.583154] gigaset: CMD Transmit (10 bytes):
> > Jul  7 00:16:08 gx110 kernel: [  746.583203] bas_gigaset: setting ATREADY time
> > Jul  7 00:16:08 gx110 kernel: [  746.585887] bas_gigaset: write_command: sent 
> > Jul  7 00:16:08 gx110 kernel: [  746.612869] gigaset: received response (6 byt
> > Jul  7 00:16:28 gx110 sshd[6134]: Accepted publickey for ts from 192.168.59.12
> > Jul  7 00:28:26 gx110 kernel: [  746.687844] gigaset: 0: if_write()
> > Jul  7 00:28:26 gx110 kernel: [  746.687944] gigaset: CMD Transmit (17 bytes):
> > Jul  7 00:28:26 gx110 kernel: [  746.688002] bas_gigaset: setting ATREADY time
> > Jul  7 00:28:26 gx110 kernel: [  746.690803] bas_gigaset: write_command: sent 
> 
> Note how the PRINTK_TIME timestamps increase in sub-second increments
> while syslogd's timestamps show an enormous gap after 00:16:08.
> 
> With kernel 2.6.17.1 on the same machine there are no such delays. All
> printk messages appear immediately, and the deltas in PRINTK_TIME and
> syslogd timestamps are quite consistent.

Hmmm. I'm assuming this is i386? Could you send me a full dmesg?

Also does booting w/ clocksource=jiffies change the behavior?

thanks
-john