Image is locked by another process

[Steve Mehlberg]

Running mpirun tests, when an abort occurs, my image ends up locked.  Is there a way to clear the lock without rebooting?  I looked for processes that I could kill, but didn't see anything worthy.

I'm using singularity v2.1 on Centos 7.2 (both host and container).

Regards,

Steve

[root@mach0 ~]# mpirun --allow-run-as-root -n 2 -H mach1,mach2 singularity exec c7 /usr/bin/ring
Process 0 sending 10 to 1, tag 201 (2 processes in ring)
Process 0 sent to 1
Process 0 decremented value: 9
Process 0 decremented value: 8
Process 0 decremented value: 7
Process 0 decremented value: 6
Process 0 decremented value: 5
Process 0 decremented value: 4
Process 0 decremented value: 3
Process 0 decremented value: 2
Process 0 decremented value: 1
Process 0 decremented value: 0
Process 0 exiting
Process 1 exiting
[root@mach0 ~]# mpirun --allow-run-as-root -n 3 -H mach0,mach1,mach2 singularity exec c7 /usr/bin/ring
--------------------------------------------------------------------------
It appears as if there is not enough space for /tmp/ompi.mach0.2291/54935/1/0/vader_segment.mach0.0 (the shared-memory backing
file). It is likely that your MPI job will now either abort or experience
performance degradation.

  Local host:  mach0
  Space Requested: 4194312 B
  Space Available: 0 B
--------------------------------------------------------------------------
[mach0:02308] create_and_attach: unable to create shared memory BTL coordinating structure :: size 134217728
[mach0:02291] 2 more processes have sent help message help-opal-shmem-mmap.txt / target full
[mach0:02291] Set MCA parameter "orte_base_help_aggregate" to 0 to see all help / error messages
^CKilled by signal 2.
Killed by signal 2.
Singularity is sending SIGKILL to child pid: 2308
Singularity is sending SIGKILL to child pid: 2309
[warn] Epoll ADD(4) on fd 31 failed.  Old events were 0; read change was 0 (none); write change was 1 (add): Bad file descriptor
^C[root@mach0 ~]singularity shell -w c7
ERROR  : Image is locked by another process
[root@mach0 ~]# tail -30 /var/log/messages
Jul 14 10:42:17 mach0 systemd: Started LSB: slurm daemon management.
Jul 14 10:42:17 mach0 systemd: Reached target Multi-User System.
Jul 14 10:42:17 mach0 systemd: Starting Multi-User System.
Jul 14 10:42:17 mach0 systemd: Starting Update UTMP about System Runlevel Changes...
Jul 14 10:42:17 mach0 systemd: Started Stop Read-Ahead Data Collection 10s After Completed Startup.
Jul 14 10:42:17 mach0 systemd: Started Update UTMP about System Runlevel Changes.
Jul 14 10:42:18 mach0 kdumpctl: kexec: loaded kdump kernel
Jul 14 10:42:18 mach0 kdumpctl: Starting kdump: [OK]
Jul 14 10:42:18 mach0 systemd: Started Crash recovery kernel arming.
Jul 14 10:42:18 mach0 systemd: Startup finished in 415ms (kernel) + 1.100s (initrd) + 4.931s (userspace) = 6.446s.
Jul 14 10:42:34 mach0 systemd: Created slice user-0.slice.
Jul 14 10:42:34 mach0 systemd: Starting user-0.slice.
Jul 14 10:42:34 mach0 systemd-logind: New session 1 of user root.
Jul 14 10:42:34 mach0 systemd: Started Session 1 of user root.
Jul 14 10:42:34 mach0 systemd: Starting Session 1 of user root.
Jul 14 10:42:36 mach0 Singularity: sexec (U=0,P=2023)> Command=exec, Container=c7, CWD=/root, Arg1=/usr/bin/ring
Jul 14 10:42:36 mach0 Singularity: sexec (U=0,P=2024)> Command=exec, Container=c7, CWD=/root, Arg1=/usr/bin/ring
Jul 14 10:42:36 mach0 Singularity: sexec (U=0,P=2024)> Image is locked by another process
Jul 14 10:42:36 mach0 kernel: loop: module loaded
Jul 14 10:43:38 mach0 Singularity: sexec (U=0,P=2050)> Command=shell, Container=c7, CWD=/root, Arg1=(null)
Jul 14 10:43:38 mach0 kernel: EXT4-fs (loop0): mounted filesystem with ordered data mode. Opts: discard
Jul 14 10:49:17 mach0 Singularity: sexec (U=0,P=2203)> Command=shell, Container=c7, CWD=/root, Arg1=(null)
Jul 14 10:49:17 mach0 kernel: EXT4-fs (loop0): mounted filesystem with ordered data mode. Opts: discard
Jul 14 10:50:39 mach0 Singularity: sexec (U=0,P=2244)> Command=exec, Container=c7, CWD=/root, Arg1=/usr/bin/ring
Jul 14 10:50:39 mach0 kernel: EXT4-fs (loop0): mounted filesystem with ordered data mode. Opts: discard
Jul 14 10:51:34 mach0 Singularity: sexec (U=0,P=2299)> Command=exec, Container=c7, CWD=/root, Arg1=/usr/bin/ring
Jul 14 10:51:34 mach0 Singularity: sexec (U=0,P=2300)> Command=exec, Container=c7, CWD=/root, Arg1=/usr/bin/ring
Jul 14 10:51:34 mach0 kernel: EXT4-fs (loop0): mounted filesystem with ordered data mode. Opts: discard
Jul 14 10:51:57 mach0 Singularity: sexec (U=0,P=2322)> Command=shell, Container=c7, CWD=/root, Arg1=(null)
Jul 14 10:51:57 mach0 Singularity: sexec (U=0,P=2322)> Image is locked by another process

[Gregory M. Kurtzer]

Hi Steve,

That means there is an active file descriptor/process still running and attached to the container maintaining a shared lock. You can run other commands against the container as long as long as the container is not being requested as --writable(-w), because that will try and obtain an exclusive lock and it will fail if there are any active shared locks. Try an "lsof /path/to/c7" to see what processes are attached to it. You may see a list like:

# lsof /tmp/Demo-2.img 

COMMAND    PID USER   FD   TYPE DEVICE   SIZE/OFF      NODE NAME

sexec   107975 root    6rR  REG  253,0 1073741856 202112247 /tmp/Demo-2.img

sexec   107977 root    6r   REG  253,0 1073741856 202112247 /tmp/Demo-2.img

bash    107982 root    6r   REG  253,0 1073741856 202112247 /tmp/Demo-2.img

Notice the two top ones are 'sexec' which are part of the Singularity process stack. Kill the bottom one, and those should go away naturally.

BTW, as long as you have installed Singularity as root, there is no need to run Singularity commands as root (unless you want to make system changes within the container).

Hope that helps!

--
You received this message because you are subscribed to the Google Groups "singularity" group.
To unsubscribe from this group and stop receiving emails from it, send an email to singularity...@lbl.gov.

--

Gregory M. Kurtzer
High Performance Computing Services (HPCS)
University of California
Lawrence Berkeley National Laboratory
One Cyclotron Road, Berkeley, CA 94720

[Steve Mehlberg]

Gregory,

Thanks for the quick suggestions.  There don't seem to be any processes attached to the container and I can't seem to run other commands (in read mode). I'm not sure what's going on.

Just lazy with root right now, I need to create a normal uid.

Steve

[root@mach0 ~]# ls -la c7
-rwxr-xr-x 1 root root 1610612769 Jul 14 10:49 c7
[root@mach0 ~]# singularity shell -w c7

ERROR  : Image is locked by another process

[root@mach0 ~]# lsof c7
[root@mach0 ~]# singularity shell c7 whoami
/usr/bin/whoami: /usr/bin/whoami: cannot execute binary file
[root@mach0 ~]#
[root@mach0 ~]# ps -ef |grep c7
root      7479  2002  0 11:49 pts/0    00:00:00 grep --color=auto c7
[root@mach0 ~]#

[Gregory M. Kurtzer]

On Thu, Jul 14, 2016 at 11:50 AM, Steve Mehlberg <sgmeh...@gmail.com> wrote:

Gregory,

Thanks for the quick suggestions.  There don't seem to be any processes attached to the container and I can't seem to run other commands (in read mode). I'm not sure what's going on.

Just lazy with root right now, I need to create a normal uid.

Ahh, ok. Been there, done that! lol

 

Steve

[root@mach0 ~]# ls -la c7
-rwxr-xr-x 1 root root 1610612769 Jul 14 10:49 c7
[root@mach0 ~]# singularity shell -w c7
ERROR  : Image is locked by another process

Can you run this command again in --debug mode (singularity --debug ....)

 

[root@mach0 ~]# lsof c7

What about the command "lslocks"?

 

[root@mach0 ~]# singularity shell c7 whoami
/usr/bin/whoami: /usr/bin/whoami: cannot execute binary file

Ahh, this is normal. You are asking the shell script to read in /usr/bin/whoami. If you want to use shell to run whoami, you must prefix it with the -c (e.g. -c "whoami [args]"), or use the 'exec' Singularity subcommand: "singularity exec c7 whoami"

 

[root@mach0 ~]#
[root@mach0 ~]# ps -ef |grep c7
root      7479  2002  0 11:49 pts/0    00:00:00 grep --color=auto c7
[root@mach0 ~]#

What kind of file system does your image exist on? Is it NFS by chance? I wonder if there is a host issue with a locking daemon or something else weird going on where it is not giving the exclusive lock properly. If this is NFS or other non local file system, can you copy the image to /tmp, rerun the MPI command to get it to fail again, and try again? 

Thanks!

[Steve Mehlberg]

Ok, I see my error with shell vs exec.  I'm running on a VM with my own space, no NFS involved.  Here is the debug command run and lsofl

[root@mach0 ~]# df -h
Filesystem             Size  Used Avail Use% Mounted on
/dev/mapper/vg1-lv001  5.7G  4.3G  1.1G  80% /
devtmpfs               911M     0  911M   0% /dev
tmpfs                  920M     0  920M   0% /dev/shm
tmpfs                  920M   41M  880M   5% /run
tmpfs                  920M     0  920M   0% /sys/fs/cgroup
/dev/vda1              190M  110M   67M  63% /boot
/dev/mapper/vg1-lv002   12G  203M   11G   2% /var
tmpfs                  184M     0  184M   0% /run/user/0
[root@mach0 ~]# singularity --debug shell -w c7
enabling debugging
ending argument loop
Exec'ing: /usr/local/libexec/singularity/cli/shell.exec -w+ '[' -f /usr/local/etc/singularity/init ']'
+ . /usr/local/etc/singularity/init
++ unset module
++ PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/root/bin:/bin:/sbin:/usr/bin:/usr/sbin
++ HISTFILE=/dev/null
++ export PATH HISTFILE
++ '[' -n '' ']'
++ '[' -n '' ']'
++ '[' -n '' ']'
++ '[' -n '' ']'
++ '[' -n '' ']'
++ '[' -n '' ']'
++ '[' -n '' ']'
++ '[' -n '' ']'
+ true
+ case ${1:-} in
+ shift
+ SINGULARITY_WRITABLE=1
+ export SINGULARITY_WRITABLE
+ true
+ case ${1:-} in
+ break
+ '[' -z c7 ']'
+ SINGULARITY_IMAGE=c7
+ export SINGULARITY_IMAGE
+ shift
+ exec /usr/local/libexec/singularity/sexec
VERBOSE [U=0,P=8045]       message.c:52:init()                        : Set messagelevel to: 5
DEBUG   [U=0,P=8045]       sexec.c:127:main()                         : Gathering and caching user info.
DEBUG   [U=0,P=8045]       privilege.c:43:get_user_privs()            : Called get_user_privs(struct s_privinfo *uinfo)
DEBUG   [U=0,P=8045]       privilege.c:54:get_user_privs()            : Returning get_user_privs(struct s_privinfo *uinfo) = 0
DEBUG   [U=0,P=8045]       sexec.c:134:main()                         : Checking if we can escalate privs properly.
DEBUG   [U=0,P=8045]       privilege.c:61:escalate_privs()            : Called escalate_privs(void)
DEBUG   [U=0,P=8045]       privilege.c:73:escalate_privs()            : Returning escalate_privs(void) = 0
DEBUG   [U=0,P=8045]       sexec.c:141:main()                         : Setting privs to calling user
DEBUG   [U=0,P=8045]       privilege.c:79:drop_privs()                : Called drop_privs(struct s_privinfo *uinfo)
DEBUG   [U=0,P=8045]       privilege.c:87:drop_privs()                : Dropping privileges to GID = '0'
DEBUG   [U=0,P=8045]       privilege.c:93:drop_privs()                : Dropping privileges to UID = '0'
DEBUG   [U=0,P=8045]       privilege.c:103:drop_privs()               : Confirming we have correct GID
DEBUG   [U=0,P=8045]       privilege.c:109:drop_privs()               : Confirming we have correct UID
DEBUG   [U=0,P=8045]       privilege.c:115:drop_privs()               : Returning drop_privs(struct s_privinfo *uinfo) = 0
DEBUG   [U=0,P=8045]       sexec.c:146:main()                         : Obtaining user's homedir
DEBUG   [U=0,P=8045]       sexec.c:150:main()                         : Obtaining file descriptor to current directory
DEBUG   [U=0,P=8045]       sexec.c:155:main()                         : Getting current working directory path string
DEBUG   [U=0,P=8045]       sexec.c:161:main()                         : Obtaining SINGULARITY_COMMAND from environment
DEBUG   [U=0,P=8045]       sexec.c:168:main()                         : Obtaining SINGULARITY_IMAGE from environment
DEBUG   [U=0,P=8045]       sexec.c:174:main()                         : Checking container image is a file: c7
DEBUG   [U=0,P=8045]       sexec.c:180:main()                         : Building configuration file location
DEBUG   [U=0,P=8045]       sexec.c:183:main()                         : Config location: /usr/local/etc/singularity/singularity.conf
DEBUG   [U=0,P=8045]       sexec.c:185:main()                         : Checking Singularity configuration is a file: /usr/local/etc/singularity/singularity.conf
DEBUG   [U=0,P=8045]       sexec.c:191:main()                         : Checking Singularity configuration file is owned by root
DEBUG   [U=0,P=8045]       sexec.c:197:main()                         : Opening Singularity configuration file
DEBUG   [U=0,P=8045]       sexec.c:210:main()                         : Checking Singularity configuration for 'sessiondir prefix'
DEBUG   [U=0,P=8045]       config_parser.c:47:config_get_key_value()  : Called config_get_key_value(fp, sessiondir prefix)
DEBUG   [U=0,P=8045]       config_parser.c:66:config_get_key_value()  : Return config_get_key_value(fp, sessiondir prefix) = NULL
DEBUG   [U=0,P=8045]       file.c:48:file_id()                        : Called file_id(c7)
VERBOSE [U=0,P=8045]       file.c:58:file_id()                        : Generated file_id: 0.64768.26052
DEBUG   [U=0,P=8045]       file.c:60:file_id()                        : Returning file_id(c7) = 0.64768.26052
DEBUG   [U=0,P=8045]       sexec.c:217:main()                         : Set sessiondir to: /tmp/.singularity-session-0.64768.26052
DEBUG   [U=0,P=8045]       sexec.c:221:main()                         : Set containername to: c7
DEBUG   [U=0,P=8045]       sexec.c:223:main()                         : Setting loop_dev_* paths
DEBUG   [U=0,P=8045]       config_parser.c:47:config_get_key_value()  : Called config_get_key_value(fp, container dir)
DEBUG   [U=0,P=8045]       config_parser.c:58:config_get_key_value()  : Return config_get_key_value(fp, container dir) = /var/singularity/mnt
DEBUG   [U=0,P=8045]       sexec.c:232:main()                         : Set image mount path to: /var/singularity/mnt
LOG     [U=0,P=8045]       sexec.c:234:main()                         : Command=shell, Container=c7, CWD=/root, Arg1=(null)
DEBUG   [U=0,P=8045]       sexec.c:247:main()                         : Set prompt to: Singularity.c7>
DEBUG   [U=0,P=8045]       sexec.c:249:main()                         : Checking if we are opening image as read/write
DEBUG   [U=0,P=8045]       sexec.c:264:main()                         : Opening image as read/write only: c7
DEBUG   [U=0,P=8045]       sexec.c:271:main()                         : Setting exclusive lock on file descriptor: 6
ERROR   [U=0,P=8045]       sexec.c:273:main()                         : Image is locked by another process

[root@mach0 ~]# lsof c7

[root@mach0 ~]# lslocks
COMMAND           PID  TYPE SIZE MODE  M START END PATH
crond             601 FLOCK   4B WRITE 0     0   0 /run/crond.pid
master            826 FLOCK  33B WRITE 0     0   0 /var/spool/postfix/pid/master.pid
master            826 FLOCK  33B WRITE 0     0   0 /var/lib/postfix/master.lock
lvmetad           478 POSIX   4B WRITE 0     0   0 /run/lvmetad.pid
slurmctld         940 POSIX   4B WRITE 0     0   0 /run/slurmctld.pid
slurmd            966 POSIX   4B WRITE 0     0   0 /run/slurmd.pid
(unknown)        2299 FLOCK   0B READ  0     0   0 /

[Gregory M. Kurtzer]

What is running at PID 2299?

[Steve Mehlberg]

Seems that process isn't running any more.  I did find this in the /var/log/messages file:

[root@mach0 ~]# cat /var/log/messages | grep 2299

Jul 14 10:51:34 mach0 Singularity: sexec (U=0,P=2299)> Command=exec, Container=c7, CWD=/root, Arg1=/usr/bin/ring

Jul 14 11:37:17 mach0 kernel: Buffer I/O error on device loop1, logical block 22299
Jul 14 11:37:17 mach0 kernel: Buffer I/O error on device loop1, logical block 22990
...

[root@mach0 ~]# ps -ef |grep 2299
root     10545  2002  0 14:15 pts/0    00:00:00 grep --color=auto 2299
[root@mach0 ~]# ps |grep 2299

[Gregory M. Kurtzer]

Very odd...

I'm concerned about the Buffer I/O errors. It is almost like the image itself has a problem with it. Did you copy this image from another system? I wonder if it is the sparseness...

Does the directory exist for /proc/2299/ ?

Can you kill it with a -9?

[Steve Mehlberg]

It is very possible that I did copy it from another system - maybe created it with singularity 2.0 and now running it with 2.1??  I will start over and recreate from scratch and see if I still have the problem.

Sorry, I checked there is no /proc/2299

The only way I've found to get the file unlocked is to reboot.  Not an issue with the little VM.

Steve

[Gregory M. Kurtzer]

I am wondering if some aspect of the sparse file has caused this. Sparse files are weird, and do require some attention when copying around. With that said, I do not think it should ever corrupt an image, but it might take along garbage data with it. One way to retest this is to go back to the original image, and tar it before sending using the -S/--sparse tar option when packaging it up. Then bring it to the other test system and see if it still does that.

Aside from that, I'm a bit confused as to what is happening. There should be no issue with 2.0 vs. 2.1, but it might be worth checking with some images also created with 2.1 on the same target system where you are seeing the problem.

[Steve Mehlberg]

Hello,

I went back and recreated everything from scratch using v2.1.  When I moved the image file to the mach1 and mach2 nodes I used tar with the -S option.  I used /tmp for the image files.  After everything was set I ran mpirun on each individual system (only starting jobs on that system) with no errors.  For some reason when I ran mpirun from mach0 and asked for jobs to be run on mach0 and another system I get the error.  The mpirun complains about not being able to create a file (already exists) and hangs.  The singularity image file on mach0 and the other system selected are locked with pids that are no longer running.

Saying all that, I decided to go back and put --debug on the singularity command in the mpirun to get you better diagnostics.  I rebooted mach0 and mach2, then reran the command and it worked correctly.  I then removed the --debug command and it worked.  I added mach1 to the mix and everything worked fine.  What? I guess the bottom line is that if the mpirun aborts (and it seems to hang) then you can get this condition.

Steve

[root@mach0 ompi]# mpirun --allow-run-as-root -np 2 -H mach2 singularity exec /tmp/c7new.img /usr/bin/ring
Process 1 exiting

Process 0 sending 10 to 1, tag 201 (2 processes in ring)
Process 0 sent to 1
Process 0 decremented value: 9
Process 0 decremented value: 8
Process 0 decremented value: 7
Process 0 decremented value: 6
Process 0 decremented value: 5
Process 0 decremented value: 4
Process 0 decremented value: 3
Process 0 decremented value: 2
Process 0 decremented value: 1
Process 0 decremented value: 0
Process 0 exiting

[root@mach0 ompi]# mpirun --allow-run-as-root -np 4 -H mach0,mach2 singularity exec /tmp/c7new.img /usr/bin/ring
ERROR  : Could not create directory /tmp/.singularity-session-0.64768.158221: File exists
ERROR  : Failed creating session directory: /tmp/.singularity-session-0.64768.158221
-------------------------------------------------------
Primary job  terminated normally, but 1 process returned
a non-zero exit code. Per user-direction, the job has been aborted.
-------------------------------------------------------
^CKilled by signal 2.
mpirun: abort is already in progress...hit ctrl-c again to forcibly terminate

[root@mach0 ompi]# singularity shell -w /tmp/c7new.img

ERROR  : Image is locked by another process

[root@mach0 ompi]# lslocks

COMMAND           PID  TYPE SIZE MODE  M START END PATH

lvmetad           473 POSIX   4B WRITE 0     0   0 /run/lvmetad.pid
crond             606 FLOCK   4B WRITE 0     0   0 /run/crond.pid
master            820 FLOCK  33B WRITE 0     0   0 /var/spool/postfix/pid/master.pid
master            820 FLOCK  33B WRITE 0     0   0 /var/lib/postfix/master.lock
slurmctld         924 POSIX   4B WRITE 0     0   0 /run/slurmctld.pid
slurmd           1103 POSIX   5B WRITE 0     0   0 /run/slurmd.pid
(unknown)        2477 FLOCK   0B READ  0     0   0 /
[root@mach0 ompi]# ls /proc/2477
ls: cannot access /proc/2477: No such file or directory
[root@mach0 ompi]# ssh mach2
Last login: Fri Jul 15 07:52:56 2016 from mach0
[root@mach2 ~]# singularity shell -w /tmp/c7new.img

ERROR  : Image is locked by another process

[root@mach2 ~]# lslocks

COMMAND           PID  TYPE SIZE MODE  M START END PATH

lvmetad           473 POSIX   4B WRITE 0     0   0 /run/lvmetad.pid
master            851 FLOCK  33B WRITE 0     0   0 /var/spool/postfix/pid/master.pid
master            851 FLOCK  33B WRITE 0     0   0 /var/lib/postfix/master.lock
(unknown)       10110 FLOCK   0B READ  0     0   0 /
crond             668 FLOCK   4B WRITE 0     0   0 /run/crond.pid
slurmd           1610 POSIX   5B WRITE 0     0   0 /run/slurmd.pid
[root@mach2 ~]# ls /proc/10110
ls: cannot access /proc/10110: No such file or directory

Good Run:

[root@mach0 ompi]# mpirun --allow-run-as-root -np 6 -H mach0,mach1,mach2 singularity exec /tmp/c7new.img /usr/bin/ring
Process 0 sending 10 to 1, tag 201 (6 processes in ring)

Process 0 sent to 1

Process 1 exiting

Process 0 decremented value: 9
Process 0 decremented value: 8
Process 0 decremented value: 7
Process 0 decremented value: 6
Process 0 decremented value: 5
Process 0 decremented value: 4
Process 0 decremented value: 3
Process 0 decremented value: 2
Process 0 decremented value: 1
Process 0 decremented value: 0
Process 0 exiting

Process 2 exiting
Process 5 exiting
Process 3 exiting
Process 4 exiting

[Gregory M. Kurtzer]

On Fri, Jul 15, 2016 at 8:26 AM, Steve Mehlberg <sgmeh...@gmail.com> wrote:

Hello,

I went back and recreated everything from scratch using v2.1.  When I moved the image file to the mach1 and mach2 nodes I used tar with the -S option.  I used /tmp for the image files.  After everything was set I ran mpirun on each individual system (only starting jobs on that system) with no errors.  For some reason when I ran mpirun from mach0 and asked for jobs to be run on mach0 and another system I get the error.  The mpirun complains about not being able to create a file (already exists) and hangs.  The singularity image file on mach0 and the other system selected are locked with pids that are no longer running.

Saying all that, I decided to go back and put --debug on the singularity command in the mpirun to get you better diagnostics.  I rebooted mach0 and mach2, then reran the command and it worked correctly.  I then removed the --debug command and it worked.  I added mach1 to the mix and everything worked fine.  What? I guess the bottom line is that if the mpirun aborts (and it seems to hang) then you can get this condition.

So does the problem seem to arise only when there is a failure on one of the processes, and MPI kills the remaining processes?

Ralph, do you know how OMPI kills the leftover processes in a job abort and what signal it uses?

(additional comments inline)

Steve

[root@mach0 ompi]# mpirun --allow-run-as-root -np 2 -H mach2 singularity exec /tmp/c7new.img /usr/bin/ring
Process 1 exiting
Process 0 sending 10 to 1, tag 201 (2 processes in ring)
Process 0 sent to 1
Process 0 decremented value: 9
Process 0 decremented value: 8
Process 0 decremented value: 7
Process 0 decremented value: 6
Process 0 decremented value: 5
Process 0 decremented value: 4
Process 0 decremented value: 3
Process 0 decremented value: 2
Process 0 decremented value: 1
Process 0 decremented value: 0
Process 0 exiting

Is /tmp NFS mounted or shared?

 

[root@mach0 ompi]# mpirun --allow-run-as-root -np 4 -H mach0,mach2 singularity exec /tmp/c7new.img /usr/bin/ring
ERROR  : Could not create directory /tmp/.singularity-session-0.64768.158221: File exists
ERROR  : Failed creating session directory: /tmp/.singularity-session-0.64768.158221
-------------------------------------------------------
Primary job  terminated normally, but 1 process returned
a non-zero exit code. Per user-direction, the job has been aborted.
-------------------------------------------------------
^CKilled by signal 2.
mpirun: abort is already in progress...hit ctrl-c again to forcibly terminate

Ahhhhh, I think you may have found a race condition in Singularity which killed one of the processes. Then the MPI killed the rest.

 

[root@mach0 ompi]# singularity shell -w /tmp/c7new.img
ERROR  : Image is locked by another process
[root@mach0 ompi]# lslocks
COMMAND           PID  TYPE SIZE MODE  M START END PATH
lvmetad           473 POSIX   4B WRITE 0     0   0 /run/lvmetad.pid
crond             606 FLOCK   4B WRITE 0     0   0 /run/crond.pid
master            820 FLOCK  33B WRITE 0     0   0 /var/spool/postfix/pid/master.pid
master            820 FLOCK  33B WRITE 0     0   0 /var/lib/postfix/master.lock
slurmctld         924 POSIX   4B WRITE 0     0   0 /run/slurmctld.pid
slurmd           1103 POSIX   5B WRITE 0     0   0 /run/slurmd.pid
(unknown)        2477 FLOCK   0B READ  0     0   0 /
[root@mach0 ompi]# ls /proc/2477
ls: cannot access /proc/2477: No such file or directory

OK, that is weird. If process 2477 is dead, there should be no active lock. I would guess this might be a kernel bug? What distribution and kernel are you running?

 

[root@mach0 ompi]# ssh mach2
Last login: Fri Jul 15 07:52:56 2016 from mach0
[root@mach2 ~]# singularity shell -w /tmp/c7new.img
ERROR  : Image is locked by another process
[root@mach2 ~]# lslocks
COMMAND           PID  TYPE SIZE MODE  M START END PATH
lvmetad           473 POSIX   4B WRITE 0     0   0 /run/lvmetad.pid
master            851 FLOCK  33B WRITE 0     0   0 /var/spool/postfix/pid/master.pid
master            851 FLOCK  33B WRITE 0     0   0 /var/lib/postfix/master.lock
(unknown)       10110 FLOCK   0B READ  0     0   0 /
crond             668 FLOCK   4B WRITE 0     0   0 /run/crond.pid
slurmd           1610 POSIX   5B WRITE 0     0   0 /run/slurmd.pid
[root@mach2 ~]# ls /proc/10110
ls: cannot access /proc/10110: No such file or directory

Very weird. Seems both nodes have the same issue..?

I wonder if I can replicate this by kill -9 the outer parent of a Singularity run. I will test when I get to my development box.

 

Good Run:

[root@mach0 ompi]# mpirun --allow-run-as-root -np 6 -H mach0,mach1,mach2 singularity exec /tmp/c7new.img /usr/bin/ring
Process 0 sending 10 to 1, tag 201 (6 processes in ring)
Process 0 sent to 1
Process 1 exiting
Process 0 decremented value: 9
Process 0 decremented value: 8
Process 0 decremented value: 7
Process 0 decremented value: 6
Process 0 decremented value: 5
Process 0 decremented value: 4
Process 0 decremented value: 3
Process 0 decremented value: 2
Process 0 decremented value: 1
Process 0 decremented value: 0
Process 0 exiting
Process 2 exiting
Process 5 exiting
Process 3 exiting
Process 4 exiting

So as long as we don't crash (or get killed), all seems fine... Interesting.

I will try and replicate the error condition.

Greg

[Steve Mehlberg]

The problem only arises when there is an error.

The tmp directory is different on each machine, it is not shared or an NFS mount.  Is that a problem?

Steve

[Gregory M. Kurtzer]

Hi Steve,

I think I have fixed the initial error you got regarding being unable to create the sessiondir. The second issue regarding file locks, I am debugging now. I'll let you know shortly when to retest.

Thanks!

[Gregory M. Kurtzer]

Hi Steve,

Sorry for the delay. The cause of the first error was an easy fix, but debugging the second had me really stumped for a while! It just so happens that I was on a conference call with several other developers a bit ago, and when we were going over this Ben Allen (LANL) pointed me in a new direction to look, and sure enough it was the loop driver in the kernel holding the file descriptor that contained the lock open! So to fix that and ensure that it won't happen again, I decided to use the LO_FLAGS_AUTOCLEAR flag option, but that brings up a potential race condition. Which luckily, after much stumpedness (and reviewing the loop kernel source) I think that I came up with a very simple workaround of simply opening the loop device itself so it doesn't auto clear itself until each process has completed! Anyway, long story short... 

Can you test the latest master and let me know if it is indeed fixed!

Thanks!

[Steve Mehlberg]

Gregory,

I have rebuilt with the latest from master this morning and repopulated everything on my small virtual cluster - mach.  Good news!  I am unable to recreate the problem.  One of my colleagues had a similar or perhaps the same problem on a larger bare metal system.  We will update that system with the latest master and test to see if the problem still occurs.

Thanks for your help,

Steve

[Gregory M. Kurtzer]

Excellent! Let me know if you find any other issues.

Thanks!