Bug 783955

That's 0x1261 BLKFLSBUF which ought to be one of the ones allowed through, I'd have thought.

Is BLKROSET affected too?
(Try 'blockdev --setro')

It seems more likely that the backport was wrong, I'll take a look.

Actually, the warning seems a false positive to me.

The BLKFLSBUF code first tries sending down the ioctl to the driver.  This is where the warning is generated.  The driver, however, will return -ENOTTY both in .9-1 and .10-2 (tried "git grep BLKFLSBUF drivers/").

This matches what I see when I do

   blockdev --setro /dev/sda3

I see "sending ioctl 125d to a partition" twice in dmesg, but a strace shows that the ioctl is succeeding.

   ioctl(3, BLKROSET, 1)                   = 0

My patches are still the most likely culprit, but it's not immediate to see what's going wrong.

Harald, can you attach a strace?  Also, can you try disabling printk ratelimiting ("sysctl -w kernel.printk_ratelimit=0 kernel.printk_ratelimit_burst=0")?

*** Bug 784076 has been marked as a duplicate of this bug. ***

I cannot reproduce the problem with mdmonitor.service (only the dmesg warning, but that's only ugly).


$ sudo mdadm --create /dev/md0 --level=1 -n2 -x1 /dev/sda5 /dev/sda6 /dev/sda7
mdadm: Note: this array has metadata at the start and
    may not be suitable as a boot device.  If you plan to
    store '/boot' on this device please ensure that
    your boot-loader understands md/v1.x metadata, or use
    --metadata=0.90
Continue creating array? y
mdadm: Defaulting to version 1.2 metadata
mdadm: array /dev/md0 started.
yakj:~ pbonzini$ sudo chmod ugo+rw /dev/md0 /dev/sda[567]
yakj:~ pbonzini$ cat /proc/mdstat 
Personalities : [raid1] 
md0 : active raid1 sda7[2](S) sda6[1] sda5[0]
      5684212 blocks super 1.2 [2/2] [UU]
      [====>................]  resync = 21.7% (1237376/5684212) finish=3.9min speed=18521K/sec
      
unused devices: <none>

$ dmesg
...
[ 2704.167988] md: md0: resync done.
[ 2704.336251] RAID1 conf printout:
[ 2704.336260]  --- wd:2 rd:2
[ 2704.336269]  disk 0, wo:0, o:1, dev:sda5
[ 2704.336276]  disk 1, wo:0, o:1, dev:sda6
$ sudo systemctl status mdmonitor.service
mdmonitor.service - Software RAID monitoring and management
	  Loaded: loaded (/etc/systemd/system/mdmonitor.service; disabled)
	  Active: active (running) since Tue, 24 Jan 2012 11:54:31 +0100; 23s ago
	 Process: 3482 ExecStart=/sbin/mdadm --monitor --program=/bin/true --scan -f --pid-file=/var/run/mdadm/mdadm.pid (code=exited, status=0/SUCCESS)
	Main PID: 3483 (mdadm)
	  CGroup: name=systemd:/system/mdmonitor.service
		  └ 3483 /sbin/mdadm --monitor --program=/bin/true --scan -f --pid-file=/var/run/mdadm/mdadm.pid
$ sudo /sbin/mdadm --detail /dev/md0
/dev/md0:
        Version : 1.2
  Creation Time : Tue Jan 24 11:46:34 2012
     Raid Level : raid1
     Array Size : 5684212 (5.42 GiB 5.82 GB)
  Used Dev Size : 5684212 (5.42 GiB 5.82 GB)
   Raid Devices : 2
  Total Devices : 3
    Persistence : Superblock is persistent

    Update Time : Tue Jan 24 11:52:07 2012
          State : clean
 Active Devices : 2
Working Devices : 3
 Failed Devices : 0
  Spare Devices : 1

           Name : yakj.usersys.redhat.com:0  (local to host yakj.usersys.redhat.com)
           UUID : b5fa445c:bc4fe9d2:e453ed71:08587c35
         Events : 17

    Number   Major   Minor   RaidDevice State
       0       8        5        0      active sync   /dev/sda5
       1       8        6        1      active sync   /dev/sda6

       2       8        7        -      spare   /dev/sda7
$ sudo sh -x /usr/sbin/raid-check 
+ '[' -f /proc/mdstat ']'
+ '[' -f /etc/sysconfig/raid-check ']'
+ . /etc/sysconfig/raid-check
++ ENABLED=yes
++ CHECK=check
++ NICE=low
++ CHECK_DEVS=md0
++ REPAIR_DEVS=md0
++ SKIP_DEVS=
+ '[' yes '!=' yes ']'
+ case "$CHECK" in
+ ionice=
+ renice=
+ case $NICE in
+ renice='-n 5'
+ ionice='-c2 -n7'
++ cut -f 1 -d ' '
++ grep '^md.*: active' /proc/mdstat
+ active_list=md0
+ '[' -z md0 ']'
+ declare -A check
+ dev_list=
+ check_list=
+ for dev in '$active_list'
+ grep -w md0
+ echo
+ '[' -f /sys/block/md0/md/sync_action ']'
++ cat /sys/block/md0/md/array_state
+ array_state=clean
+ '[' clean '!=' clean -a clean '!=' active ']'
++ cat /sys/block/md0/md/sync_action
+ sync_action=idle
+ '[' idle '!=' idle ']'
+ ck=
+ echo md0
+ grep -w md0
+ ck=repair
+ grep -w md0
+ echo md0
+ ck=check
+ '[' -z check ']'
+ dev_list=' md0'
+ check[$dev]=check
+ '[' check = check ']'
+ check_list=' md0'
+ '[' -z ' md0' ']'
+ for dev in '$dev_list'
+ echo check
+ resync_pid=
+ wait=10
+ '[' 10 -gt 0 -a -z '' ']'
+ sleep 6
+ let wait--
++ ps -ef
++ awk -v mddev=md0 'BEGIN { pattern = "^\\[" mddev "_resync]$" } $8 ~ pattern { print $2 }'
+ resync_pid=3822
+ '[' 9 -gt 0 -a -z 3822 ']'
+ '[' -n 3822 -a -n '-n 5' ']'
+ renice -n 5 -p 3822
+ '[' -n 3822 -a -n '-c2 -n7' ']'
+ ionice -c2 -n7 -p 3822
+ '[' -z ' md0' ']'
+ checking=1
+ '[' 1 -ne 0 ']'
+ sleep 60
+ checking=0
+ for dev in '$check_list'
++ cat /sys/block/md0/md/sync_action
+ sync_action=idle
+ '[' idle '!=' idle ']'
+ '[' 0 -ne 0 ']'
+ for dev in '$check_list'
++ cat /sys/block/md0/md/mismatch_cnt
+ mismatch_cnt=0
++ cat /sys/block/md0/md/level
+ raid_lvl=raid1
+ '[' raid1 = raid1 -o raid1 = raid10 ']'
+ continue
$ dmesg
...
[ 3333.854826] md: data-check of RAID array md0
[ 3333.854830] md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
[ 3333.854832] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
[ 3333.854836] md: using 128k window, over a total of 5684212k.
[ 3639.920121] md: md0: data-check done.
$ sudo systemctl status mdmonitor.service
[sudo] password for pbonzini: 
mdmonitor.service - Software RAID monitoring and management
	  Loaded: loaded (/etc/systemd/system/mdmonitor.service; disabled)
	  Active: active (running) since Tue, 24 Jan 2012 11:54:31 +0100; 14min ago
	 Process: 3482 ExecStart=/sbin/mdadm --monitor --program=/bin/true --scan -f --pid-file=/var/run/mdadm/mdadm.pid (code=exited, status=0/SUCCESS)
	Main PID: 3483 (mdadm)
	  CGroup: name=systemd:/system/mdmonitor.service
		  └ 3483 /sbin/mdadm --monitor --program=/bin/true --scan -f --pid-file=/var/run/mdadm...

And here is my service file:

$ cat /etc/systemd/system/mdmonitor.service 
[Unit]
Description=Software RAID monitoring and management
After=syslog.target
ConditionPathExists=/etc/mdadm.conf

[Service]
Type=forking
PIDFile=/var/run/mdadm/mdadm.pid
EnvironmentFile=-/etc/sysconfig/mdmonitor
ExecStart=/sbin/mdadm --monitor --program=/bin/true --scan -f --pid-file=/var/run/mdadm/mdadm.pid

[Install]
WantedBy=multi-user.target


1) Can you check in /var/log/messages _why_ did mdmonitor fail?

2) Does mdmonitor fail with the non-test kernel?

1) 
systemd does not make much outputs except "entered failed state"

2) 
AFAIK yes, i noticed this last thursday on my workstation and the testing-kernel was on koji after that

1) Nothing in /var/log/messages, such as

Jan 24 11:52:11 yakj mdadm[3395]: mdadm: No mail address or alert command - not monitoring.
Jan 24 11:52:11 yakj systemd[1]: mdmonitor.service: control process exited, code=exited status=1
Jan 24 11:52:11 yakj systemd[1]: Unit mdmonitor.service entered failed state.

?

2) So the mdmonitor failure is not a regression, right?

seems to belong to the mdadm-bugreport, so one part of it is a kernel-regression and the other one a bug in mdadm itself - sorry for the confusion

The kernel problem is not a bug, it's just ugly to have a warning in dmesg but that's what the warning was for---to make sure that problematic cases would be noticed.

For the mdadm, please reproduce on F16 since you're using non-standard init scripts.

in my opinion "The kernel problem is not a bug, it's just ugly to have a warning in dmesg" is wrong, there should be no warnings in the state software is shipped with the distribution for normal behavior!

We added a warning because we're not changing behavior yet; the warning must be there so that we know exactly how the behavior will change, and so that we know that changes will not be harmful.

mdadm: sending ioctl 1261 to a partition! Also present in Fedora 16 please reopen.

(In reply to comment #14)
> mdadm: sending ioctl 1261 to a partition! Also present in Fedora 16 please
> reopen.

It's information, not a bug, so no need to reopen.

Right - it's information for developers, but not a warning for the sysadmin.  The trouble here is that it's being sent with kern.warn severity, which causes vt console spew for the default printk level.  This breaks many apps on the vt (watch, top, etc.) which are commonly run by sysadmins.

(disable these on console with, e.g.: echo '4 4 1 4' > /proc/sys/kernel/printk or set the kernel.printk sysctl) 

I'd think 5, 6, or 7 would be more appropriate severities as far as RFC 5424 goes, but it's also worth asking why this is the only part of Fedora that's behaving this way (at least in common usage).  Is this important enough to force everybody who runs mdmonitor to adjust kernel.printk if they use virtual terminals? (not to mention the time they'll need to figure out that's what they need to do).

The warnings will go away soon...