Part of Spinning up disk... ....ready logged on separate line and as warning (default level)

[Paul Menzel]

Dear Linux folks,


Plugging in an external HDD over USB, Linux logs a warning:

    $ dmesg --level=warn
    [  244.677769] ....ready

With the messages around it:

    [  243.663382] sd 10:0:0:0: [sdb] Spinning up disk...
    [  244.677769] ....ready

The code in `drivers/scsi/sd.c` suggests that now line break should 
happen, as no `\n` is used and `printk(KERN_CONT ".")`. If that would 
work, the message would also be logged with level `KERN_NOTICE`.

Is the macro somehow getting in the way?

    sd_printk(KERN_NOTICE, sdkp, "Spinning up disk...");

From `drivers/scsi/sd.h`:

```
#define sd_printk(prefix, sdsk, fmt, a...)                              \
        (sdsk)->disk ?                                                  \
              sdev_prefix_printk(prefix, (sdsk)->device,                \
                                 (sdsk)->disk->disk_name, fmt, ##a) :   \
              sdev_printk(prefix, (sdsk)->device, fmt, ##a)
```

From `drivers/scsi/scsi_logging.c`:

```
void sdev_prefix_printk(const char *level, const struct scsi_device *sdev,
                        const char *name, const char *fmt, ...)
{
        va_list args;
        char *logbuf;
        size_t off = 0, logbuf_len;

        if (!sdev)
                return;

        logbuf = scsi_log_reserve_buffer(&logbuf_len);
        if (!logbuf)
                return;

        if (name)
                off += scnprintf(logbuf + off, logbuf_len - off,
                                 "[%s] ", name);
        if (!WARN_ON(off >= logbuf_len)) {
                va_start(args, fmt);
                off += vscnprintf(logbuf + off, logbuf_len - off, fmt, 
args);
                va_end(args);
        }
        dev_printk(level, &sdev->sdev_gendev, "%s", logbuf);
        scsi_log_release_buffer(logbuf);
}
EXPORT_SYMBOL(sdev_prefix_printk);
```

Also, there are four dots in `....ready`, but the log timestamps only 
differ by one seconds.

    /* Wait 1 second for next try */
    msleep(1000);
    printk(KERN_CONT ".");

Any idea, how that can be?


Kind regards,

Paul