Flashsystem 5000 collection broken

vadim

Everything worked fine until this morning, but at some point STOR2RRD stopped receiving data from this Flashsystem. Connection test passing both in GUI and in CLI. What could possibly go wrong?

vadim

Some logs:

$ tail /home/lpar2rrd/stor2rrd/logs/error.log-fs5030
/home/lpar2rrd/stor2rrd/bin/data_load.pl:109 : No such process
[Thu Dec 9 22:25:06 2021] data_load.pl: Use of uninitialized value $RRDp::error_mode in string eq at /usr/lib64/perl5/vendor_perl/RRDp.pm line 168.
Thu Dec 9 22:25:09 2021: fs5030 : data_load.pl failed: ERROR: opening '/home/lpar2rrd/stor2rrd/data/fs5030/VOLUME/0010.rrd': Permission denied at /home/lpar2rrd/stor2rrd/bin/LoadDataModule.pm line 44618.
/home/lpar2rrd/stor2rrd/bin/data_load.pl:109 : No such process
[Thu Dec 9 22:30:09 2021] data_load.pl: Use of uninitialized value $RRDp::error_mode in string eq at /usr/lib64/perl5/vendor_perl/RRDp.pm line 168.
Thu Dec 9 22:30:12 2021: fs5030 : data_load.pl failed: ERROR: opening '/home/lpar2rrd/stor2rrd/data/fs5030/VOLUME/0010.rrd': Permission denied at /home/lpar2rrd/stor2rrd/bin/LoadDataModule.pm line 44618.
/home/lpar2rrd/stor2rrd/bin/data_load.pl:109 : No such process
[Thu Dec 9 22:35:07 2021] data_load.pl: Use of uninitialized value $RRDp::error_mode in string eq at /usr/lib64/perl5/vendor_perl/RRDp.pm line 168.
Thu Dec 9 22:35:10 2021: fs5030 : data_load.pl failed: ERROR: opening '/home/lpar2rrd/stor2rrd/data/fs5030/VOLUME/0010.rrd': Permission denied at /home/lpar2rrd/stor2rrd/bin/LoadDataModule.pm line 44618.
/home/lpar2rrd/stor2rrd/bin/data_load.pl:109 : No such process


$ tail /home/lpar2rrd/stor2rrd/logs/output.log-fs5030
/home/lpar2rrd/stor2rrd/bin/svc_stor_load.sh: 2021-12-09_22:15 : Command data_load.pl ends with return code 1
Thu Dec 9 22:15:55 2021 - INFO - svcperf.pl: Process IOSTAT files - Time: 211209_221451 Nodes: 2
/home/lpar2rrd/stor2rrd/bin/svc_stor_load.sh: 2021-12-09_22:20 : Command data_load.pl ends with return code 1
Thu Dec 9 22:20:55 2021 - INFO - svcperf.pl: Process IOSTAT files - Time: 211209_221951 Nodes: 2
/home/lpar2rrd/stor2rrd/bin/svc_stor_load.sh: 2021-12-09_22:25 : Command data_load.pl ends with return code 1
Thu Dec 9 22:25:55 2021 - INFO - svcperf.pl: Process IOSTAT files - Time: 211209_222451 Nodes: 2
/home/lpar2rrd/stor2rrd/bin/svc_stor_load.sh: 2021-12-09_22:30 : Command data_load.pl ends with return code 1
Thu Dec 9 22:30:55 2021 - INFO - svcperf.pl: Process IOSTAT files - Time: 211209_222951 Nodes: 2
/home/lpar2rrd/stor2rrd/bin/svc_stor_load.sh: 2021-12-09_22:35 : Command data_load.pl ends with return code 1
Thu Dec 9 22:35:55 2021 - INFO - svcperf.pl: Process IOSTAT files - Time: 211209_223451 Nodes: 2

Pavel

ls -l /home/lpar2rrd/stor2rrd/data/fs5030/VOLUME/0010.rrd

ls -ld /home/lpar2rrd/stor2rrd/data/fs5030/VOLUME

vadim

$ ls -l /home/lpar2rrd/stor2rrd/data/fs5030/VOLUME/0010.rrd
-rwxr-xr-x 1 root root 2385512 Oct 27 12:05 /home/lpar2rrd/stor2rrd/data/fs5030/VOLUME/0010.rrd

$ ls -ld /home/lpar2rrd/stor2rrd/data/fs5030/VOLUME
drwxr-xr-x 2 lpar2rrd lpar2rrd 4096 Dec  9 10:40 /home/lpar2rrd/stor2rrd/data/fs5030/VOLUME

vadim

...
-rwxr-xr-x 1 lpar2rrd lpar2rrd 1855544 Dec  9 10:55 0008.rrc
-rwxr-xr-x 1 lpar2rrd lpar2rrd 2385512 Dec  9 10:55 0008.rrd
-rwxr-xr-x 1 lpar2rrd lpar2rrd 1855544 Dec  9 10:55 0009.rrc
-rwxr-xr-x 1 lpar2rrd lpar2rrd 2385512 Dec  9 10:55 0009.rrd
-rwxr-xr-x 1 root     root     1855544 Oct 27 12:05 0010.rrc
-rwxr-xr-x 1 root     root     2385512 Oct 27 12:05 0010.rrd
-rwxr-xr-x 1 lpar2rrd lpar2rrd 1855544 Dec  9 10:55 0011.rrc
-rwxr-xr-x 1 lpar2rrd lpar2rrd 2385512 Dec  9 10:55 0011.rrd
-rwxr-xr-x 1 lpar2rrd lpar2rrd 1855544 Dec  9 10:55 0012.rrc
-rwxr-xr-x 1 lpar2rrd lpar2rrd 2385512 Dec  9 10:55 0012.rrd
...

Amuzing... Can't imagine why. Should use chown?

Pavel

cd /home/lpar2rrd/stor2rrd

chown -R lpar2rrd *

you perhaps run under root load_svcperf.sh on 27th od Oct.

Make sure there is no stor2rrd  jobs in root's crontab as well.

vadim

Fixed. Thank you so much!