Skip to contentSkip to conversation

dmesg spam

DISCUSSION Andrew Morton 4 participants 11 messages Feb 3, 2008 – Feb 5, 2008 SCSI

lore
Share & tools
lore

Andrew Morton

author
#0 lore raw

With latest -mm, running fc8 I am getting this in the logs, once per second.

sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.

#1 lore raw
Quoted 2 lines · Andrew Morton

With latest -mm, running fc8 I am getting this in the logs,

                           ^^^

=> SCSI/libata

cc ing Jeff
Quoted 11 lines

once per second.

sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.

author
#2 lore raw
Quoted 19 lines · On Mon, 4 Feb 2008 15:24:55 +0100 Bartlomiej Zolnierkiewicz…
Quoted 2 lines · Andrew Morton

With latest -mm, running fc8 I am getting this in the logs,

                           ^^^

=> SCSI/libata

cc ing Jeff
Quoted 11 lines

once per second.

sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.

Well.. it's coming out of the kernel. Presumably it's that cdrom polling thing in KDE. James recently made changes to sr_ioctl.c but I've been buried in more terminal regressions than this one.

#3 lore raw
Quoted 21 lines · Andrew Morton
Quoted 18 lines · On Mon, 4 Feb 2008 15:24:55 +0100 Bartlomiej Zolnierkiewicz…
Quoted 1 line · Andrew Morton

With latest -mm, running fc8 I am getting this in the logs,

                           ^^^

=> SCSI/libata

cc ing Jeff
Quoted 11 lines

once per second.

sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.

Quoted 3 lines

Well.. it's coming out of the kernel. Presumably it's that cdrom polling thing in KDE. James recently made changes to sr_ioctl.c but I've been buried in more terminal regressions than this one.

I don't see this in upstream... can you isolate it to a particular git tree?

Clearly userland is initiating a once-per-second poll. That is quite normal for 99% of CDROMs, which do not support async notification.

But also clearly that message is printk'd way too much in your case.

Jeff

maintainer
#4 lore raw
Quoted 22 lines · Jeff Garzik
Quoted 21 lines · Andrew Morton
Quoted 18 lines · On Mon, 4 Feb 2008 15:24:55 +0100 Bartlomiej Zolnierkiewicz…
Quoted 1 line · Andrew Morton

With latest -mm, running fc8 I am getting this in the logs,

                           ^^^

=> SCSI/libata

cc ing Jeff
Quoted 11 lines

once per second.

sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.

Quoted 6 lines
Quoted 3 lines

Well.. it's coming out of the kernel. Presumably it's that cdrom polling thing in KDE. James recently made changes to sr_ioctl.c but I've been buried in more terminal regressions than this one.

I don't see this in upstream... can you isolate it to a particular git tree?

It's here in sr_ioctl.c:

int sr_do_ioctl(Scsi_CD *cd, struct packet_command *cgc)
{
[...]
case NOT_READY: /* This happens if there is no disc in
drive */
[...]
if (!cgc->quiet)
printk(KERN_INFO "%s: CDROM not ready.
Make sure there is a disc in the drive.\n", cd->cdi.name);

#ifdef DEBUG
                        scsi_print_sense_hdr("sr", &sshdr);

#endif

Quoted 4 lines

Clearly userland is initiating a once-per-second poll. That is quite normal for 99% of CDROMs, which do not support async notification.

But also clearly that message is printk'd way too much in your case.

I'm not averse to simply nuking the printk ... it's probably valueless in a modern kernel, since something dbussy is supposed to tell you to put a CD in the drive, not something in the kernel.

I am however interested to see if it's a symptom of something else that might be a bigger problem.

James

#5 lore raw
Quoted 1 line · James Bottomley

It's here in sr_ioctl.c:

Ah, indeed. My grep-fu sucks today.

Quoted 3 lines

I'm not averse to simply nuking the printk ... it's probably valueless in a modern kernel, since something dbussy is supposed to tell you to put a CD in the drive, not something in the kernel.

The reverse... dbussy/HAL is implementing autodetection of media insertion, by polling ad infinitum.

Jeff

maintainer
#6 lore raw
Quoted 6 lines · Jeff Garzik
Quoted 1 line · James Bottomley

It's here in sr_ioctl.c:

Ah, indeed. My grep-fu sucks today.

Quoted 6 lines
Quoted 3 lines

I'm not averse to simply nuking the printk ... it's probably valueless in a modern kernel, since something dbussy is supposed to tell you to put a CD in the drive, not something in the kernel.

The reverse... dbussy/HAL is implementing autodetection of media insertion, by polling ad infinitum.

Understood ... I meant the day of the user relying on a message from a kernel printk to tell them they need a CD in the drive is long over.

James

author
#7 lore raw
Quoted 12 lines · On Mon, 04 Feb 2008 14:44:18 -0600 James Bottomley…
Quoted 10 lines · Jeff Garzik
Quoted 1 line · James Bottomley

It's here in sr_ioctl.c:

Ah, indeed. My grep-fu sucks today.

Quoted 3 lines

I'm not averse to simply nuking the printk ... it's probably valueless in a modern kernel, since something dbussy is supposed to tell you to put a CD in the drive, not something in the kernel.

Quoted 6 lines
Quoted 2 lines

The reverse... dbussy/HAL is implementing autodetection of media insertion, by polling ad infinitum.

Understood ... I meant the day of the user relying on a message from a kernel printk to tell them they need a CD in the drive is long over.

OK, sorry, I'm hopelessly full of it. These messages also are produced by 2.6.24, 2.6.23 and 2.6.23.1-49.fc8.

I don't think anyone would miss this message were it to bite the D key.

maintainer
#8 lore raw
In reply to Andrew Morton
Quoted 22 lines · Andrew Morton
Quoted 19 lines · On Mon, 4 Feb 2008 15:24:55 +0100 Bartlomiej Zolnierkiewicz…
Quoted 2 lines · Andrew Morton

With latest -mm, running fc8 I am getting this in the logs,

                           ^^^

=> SCSI/libata

cc ing Jeff
Quoted 11 lines

once per second.

sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.
sr0: CDROM not ready. Make sure there is a disc in the drive.

Quoted 3 lines

Well.. it's coming out of the kernel. Presumably it's that cdrom polling thing in KDE. James recently made changes to sr_ioctl.c but I've been buried in more terminal regressions than this one.

You're thinking of this one?

commit 210ba1d1724f5c4ed87a2ab1a21ca861a915f734

Author: James Bottomley <[email protected]>
Date:   Sat Jan 5 10:39:51 2008 -0600

[SCSI] sr: update to follow tray status correctly

Based on an original patch from: David Martin <[email protected]>

You could try reversing it if you want, but I'm not certain that's the problem (the patch only affected sr_do_status, which is a cdrom internal thing).

The message comes from sr_ioctl.c:sr_do_ioctl(). Which means some user level application is poking the drive with a command that's returning NOT_READY. Apparently it will shut up if quiet is set in the packet command structure.

It could be the application is getting the wrong idea of the status from sr_do_staus() which leads it to send commands which require a medium? But we'll need a bit of debugging to determine this.

James

#9 lore raw
Quoted 8 lines · James Bottomley

The message comes from sr_ioctl.c:sr_do_ioctl(). Which means some user level application is poking the drive with a command that's returning NOT_READY. Apparently it will shut up if quiet is set in the packet command structure.

It could be the application is getting the wrong idea of the status from sr_do_staus() which leads it to send commands which require a medium? But we'll need a bit of debugging to determine this.

Userland polling of the cdrom is quite normal (if unfortunately), regardless of medium presence. Probably HAL or dbus.

In theory, the userland app should (a) set quiet and (b) handle not-ready condition just fine.

I presume that (b) is ok, since not-ready just means to continue polling the cdrom ad infinitum, until media appears.

A useful experiment, if only to confirm the obvious, would be to insert some media.

What controller and device is in use?

Jeff

author
#10 lore raw
Quoted 17 lines · On Mon, 04 Feb 2008 15:21:54 -0500 Jeff Garzik <[email protected]> wrote:
Quoted 8 lines · James Bottomley

The message comes from sr_ioctl.c:sr_do_ioctl(). Which means some user level application is poking the drive with a command that's returning NOT_READY. Apparently it will shut up if quiet is set in the packet command structure.

It could be the application is getting the wrong idea of the status from sr_do_staus() which leads it to send commands which require a medium? But we'll need a bit of debugging to determine this.

Userland polling of the cdrom is quite normal (if unfortunately), regardless of medium presence. Probably HAL or dbus.

In theory, the userland app should (a) set quiet and (b) handle not-ready condition just fine.

Quoted 8 lines

I presume that (b) is ok, since not-ready just means to continue polling the cdrom ad infinitum, until media appears.

A useful experiment, if only to confirm the obvious, would be to insert some media.

What controller and device is in use?

It's the thinkpad t61p. Currently five miles away, powered off. It's all new Intel stuff iirc.

http://userweb.kernel.org/~akpm/dmesg-t61p.txt has some info but not the right info afaict.

Bisection time I guess. That'll be a new experience.