2

Update #1:

I just gave an extra layer of testing, writing a shell script (.sh, #!/bin/bash) and a php script to be executed by php's cli.

Bash works.

It seems that it's not the Apache's HTTP context, but PHP itself that is causing the problems. Because a simple php raider.php run from root's shell has the same 2 problems mentioned originally.


I am building an appliance that has an WebOS on top of. WebOS is being hosted with Apache running as http:http. Since WebOS needs access to OS (root), sudoers are set up - to allow http ALL with NOPASSWD.

Please don't educate about processes being run as root - the environment is controlled, and has been working for 2 years now with over 40 units shipped and no problems reported.

Commands are run by php (mod_php5 for Apache) with proc_open from a HTTP request context.

Every command seems to be working fine, except for mdadm --create. When I attempt to create an array there are random outcomes depending on the RAID level I have chosen to make.

Previously I've had a namespacing problem, but that's not the case anymore. The problem started to appear after some OS updates (don't know when exactly, this is the old version of the WebOS that isn't working and had to be brought up as of recent and, apparently, needs to be fixed - there is also a new version which works ok (it has a different command execution cycle)).

I am using mdadm_udev initramfs hook to assemble RAID's upon start. I have left /etc/mdadm.conf empty, because mdadm_udev seems to assemble the RAID's properly based on their metadata. The only catch, though, is that when it assembles them, it names the raid based on <hostname>:<raidname>.

Due to the catch above, I am using mdadm --create /dev/md/<hostname>:stoneshare ..., which seems to be running fine from CLI no matter what's the user (non-root users run as sudo and succeed), the problems come when ran through HTTP context.

Scenario #1, RAID0:

<?php

$command = sprintf('sudo mdadm --create /dev/md/%s:stoneshare --level 0 --raid-devices 2 /dev/sdb1 /dev/sdc1');
proc_open($command, /* ... */, /* ... */);

RAID gets created, but, where CLI makes the RAID on /dev/md127 and symlinks to /dev/md/<hostname>:<sharename>, by running the above script, I end up with /dev/md127 with no link:

[root@stone ~]# mdadm --detail --scan
ARRAY /dev/md127 metadata=1.2 name=stone:stoneshare UUID=7329e458:96be442a:84f616d8:fd4ba42e

[root@stone ~]# ls -la /dev/md*
brw-rw---- 1 root disk 9, 127 Jul 30 11:48 /dev/md127

Scenario #2, RAID1:

<?php

$command = sprintf('sudo mdadm --create /dev/md/%s:stoneshare --level 1 --assume-clean --raid-devices 2 /dev/sdb1 /dev/sdc1');
proc_open($command, /* ... */, /* ... */);

Check:

[root@stone ~]# mdadm --detail --scan
ARRAY /dev/md/stone:stoneshare metadata=1.2 name=stone:stoneshare UUID=7329e458:96be442a:84f616d8:fd4ba42e

[root@stone ~]# ls -la /dev/md*
brw-rw---- 1 root disk 9, 127 Jul 30 11:48 /dev/md127

/dev/md:
total 0
drwxr-xr-x  2 root root   60 Jul 30 12:17 .
drwxr-xr-x 19 root root 3080 Jul 30 12:17 ..
lrwxrwxrwx  1 root root   10 Jul 30 12:17 stone:stoneshare -> /dev/md127

Weirdly, but the symlink is created, there is a different problem though - upon RAID's creation, randomly either /dev/sdb1 or /dev/sdc1 is automatically marked as faulty. The RAID gets created and started, but is running with 1 drive. Sometimes neither of the drives is marked faulty and RAID is created with no problems at all.

I have handpicked, what I found as relevant information for the device failure:

[root@stone ~]# journalctl -xb
Jul 30 11:39:43 stone kernel: md: bind<sdb1>
Jul 30 11:39:43 stone kernel: md: bind<sdc1>
Jul 30 11:39:43 stone kernel: md/raid1:md127: active with 2 out of 2 mirrors
Jul 30 11:39:43 stone kernel: created bitmap (8 pages) for device md127
Jul 30 11:39:43 stone kernel: md127: bitmap initialized from disk: read 1 pages, set 14903 of 14903 bits
Jul 30 11:39:43 stone kernel: md127: detected capacity change from 0 to 1000068874240
Jul 30 11:39:43 stone kernel:  md127: unknown partition table
Jul 30 11:39:43 stone systemd[1]: Starting MD array monitor...
Jul 30 11:39:43 stone systemd[1]: About to execute: /usr/lib/systemd/scripts/mdadm_env.sh
Jul 30 11:39:43 stone systemd[1]: Forked /usr/lib/systemd/scripts/mdadm_env.sh as 457
Jul 30 11:39:43 stone systemd[1]: mdmonitor.service changed failed -> start-pre
Jul 30 11:39:43 stone systemd[457]: Executing: /usr/lib/systemd/scripts/mdadm_env.sh
Jul 30 11:39:43 stone systemd[457]: Failed at step EXEC spawning /usr/lib/systemd/scripts/mdadm_env.sh: No such file or directory
Jul 30 11:39:43 stone systemd[1]: Received SIGCHLD from PID 457 ((m_env.sh)).
Jul 30 11:39:43 stone systemd[1]: Child 457 ((m_env.sh)) died (code=exited, status=203/EXEC)
Jul 30 11:39:43 stone systemd[1]: Child 457 belongs to mdmonitor.service
Jul 30 11:39:43 stone systemd[1]: mdmonitor.service: control process exited, code=exited status=203
Jul 30 11:39:43 stone systemd[1]: mdmonitor.service got final SIGCHLD for state start-pre
Jul 30 11:39:43 stone systemd[1]: About to execute: /sbin/mdadm --monitor $MDADM_MONITOR_ARGS
Jul 30 11:39:43 stone systemd[1]: Forked /sbin/mdadm as 460
Jul 30 11:39:43 stone systemd[1]: mdmonitor.service changed start-pre -> running
Jul 30 11:39:43 stone systemd[1]: Job mdmonitor.service/start finished, result=done
Jul 30 11:39:43 stone systemd[1]: Started MD array monitor.
Jul 30 11:39:43 stone kernel: md: md127 still in use.
Jul 30 11:39:43 stone kernel: md/raid1:md127: Disk failure on sdb1, disabling device.
                              md/raid1:md127: Operation continuing on 1 devices.
Jul 30 11:39:43 stone mdadm[460]: mdadm: No mail address or alert command - not monitoring.
Jul 30 11:39:43 stone systemd[460]: Executing: /sbin/mdadm --monitor --scan
Jul 30 11:39:43 stone systemd[1]: Received SIGCHLD from PID 460 (mdadm).
Jul 30 11:39:43 stone systemd[1]: Child 460 (mdadm) died (code=exited, status=1/FAILURE)
Jul 30 11:39:43 stone systemd[1]: Child 460 belongs to mdmonitor.service
Jul 30 11:39:43 stone systemd[1]: mdmonitor.service: main process exited, code=exited, status=1/FAILURE
Jul 30 11:39:43 stone systemd[1]: mdmonitor.service changed running -> failed
Jul 30 11:39:43 stone systemd[1]: Unit mdmonitor.service entered failed state.
Jul 30 11:39:43 stone systemd[1]: mdmonitor.service: cgroup is empty
Jul 30 11:39:43 stone kernel: RAID1 conf printout:
Jul 30 11:39:43 stone kernel:  --- wd:1 rd:2
Jul 30 11:39:43 stone kernel:  disk 0, wo:1, o:0, dev:sdb1
Jul 30 11:39:43 stone kernel:  disk 1, wo:0, o:1, dev:sdc1
Jul 30 11:39:43 stone systemd[1]: Got disconnect on private connection.
Jul 30 11:39:43 stone kernel: RAID1 conf printout:
Jul 30 11:39:43 stone kernel:  --- wd:1 rd:2
Jul 30 11:39:43 stone kernel:  disk 1, wo:0, o:1, dev:sdc1
Jul 30 11:39:43 stone kernel: md: unbind<sdb1>
Jul 30 11:39:43 stone kernel: md: export_rdev(sdb1)

Thought, I doubt that mdmonitor is essential for creating the RAID.


Both RAID's are perfectly assembled when ran from CLI, no problems encountered.

Drives, per S.M.A.R.T. are healthy.

The UUID's in reality are not equal, I just made the examples up out of a single RAID.


What am I doing wrong here, that is causing such inconsistencies?

1

TL;DR.

I found out where the problem lies! I had to sleep some time between some of the partitioning tasks. Apparently I stumbled upon concurrency issues.

In-depth:

It looks like when a process completes, it doesn't mean that kernel has already completed it's role in the process (in case kernel has to do something after given process). In my case, that was partitioning - apparently, I started mdadm --create too soon, when kernel had not yet updated some of the partition changes. And yes, I had partprobe inbetween, but it looked like it isn't aware of changes either.

I started debugging this with shell scripts, cli php scripts, web scripts, until I stumbled upon:

[root@stone /] parted -s /dev/sdb mklabel gpt unit GB mkpart primary 0 100%
[root@stone /] parted -s /dev/sdc mklabel gpt unit GB mkpart primary 0 100%

[root@stone /] partprobe

[root@stone /] lsblk
sda      8:0    0  55.9G  0 disk
├─sda1   8:1    0     1M  0 part
├─sda2   8:2    0   500M  0 part /boot/efi
├─sda3   8:3    0   500M  0 part [SWAP]
└─sda4   8:4    0  54.9G  0 part /
sdb      8:16   0 931.5G  0 disk
└─sdb1   8:17   0 931.5G  0 part
sdc      8:32   0 931.5G  0 disk

When the commands were executed with no intervals between them, allowing the CPU to process them as fast as possible - I noticed that /dev/sdc has not yet updated it's partition table.

Apparently, the next command after that partprobe is mdadm --create, which started with no changes to the partition table, resulting in weird behavior.

Might be that my observations and assumptions are completely wrong, but at least that's how I can explain the situation logically for myself.

Yes, the fix was to add sleep in between the calls:

[root@stone /] parted -s /dev/sdb mklabel gpt unit GB mkpart primary 0 100%
[root@stone /] parted -s /dev/sdc mklabel gpt unit GB mkpart primary 0 100%

[root@stone /] sleep 1

[root@stone /] partprobe

[root@stone /] sleep 1

[root@stone /] lsblk
sda      8:0    0  55.9G  0 disk
├─sda1   8:1    0     1M  0 part
├─sda2   8:2    0   500M  0 part /boot/efi
├─sda3   8:3    0   500M  0 part [SWAP]
└─sda4   8:4    0  54.9G  0 part /
sdb      8:16   0 931.5G  0 disk
└─sdb1   8:17   0 931.5G  0 part
sdc      8:32   0 931.5G  0 disk

That fixed the issue.

In the end, though, I still cannot find a logical explanation as to why in RAID0 case it didn't make the symlink, where it did in RAID1 case. I simply cannot understand what there is to drive readiness that prevents symlink creation...

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.