Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

podman checkpoint fails #11001

Closed
vikas-goel opened this issue Jul 20, 2021 · 40 comments
Closed

podman checkpoint fails #11001

vikas-goel opened this issue Jul 20, 2021 · 40 comments
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. stale-issue

Comments

@vikas-goel
Copy link
Contributor

vikas-goel commented Jul 20, 2021

Is this a BUG REPORT or FEATURE REQUEST? (leave only one on its own line)

/kind bug

Description

podman checkpoint operation fails

Steps to reproduce the issue:

  1. Start a podman container
  2. Run podman container checkpoint --leave-running --tcp-established tme-mas-01

Describe the results you received:

# podman container checkpoint  --leave-running --tcp-established tme-mas-01
ERRO[0000] criu failed: type NOTIFY errno 0
log file: /var/lib/containers/storage/overlay-containers/a84fc6f6f29369b64abffcbdb354347a89bb565c50542385250e4a233b83ca2a/userdata/dump.log
Error: `/usr/bin/runc checkpoint --image-path /var/lib/containers/storage/overlay-containers/a84fc6f6f29369b64abffcbdb354347a89bb565c50542385250e4a233b83ca2a/userdata/checkpoint --work-path /var/lib/containers/storage/overlay-containers/a84fc6f6f29369b64abffcbdb354347a89bb565c50542385250e4a233b83ca2a/userdata --leave-running --tcp-established --leave-running a84fc6f6f29369b64abffcbdb354347a89bb565c50542385250e4a233b83ca2a` failed: exit status 1

dump.log

Describe the results you expected:
Should have created a checkpoint

Additional information you deem important (e.g. issue happens only occasionally):
Consistently

Output of podman version:

Version:      3.3.0-dev
API Version:  3.3.0-dev
Go Version:   go1.16.5
Git Commit:   6150f039365eafa00ba88382c3343769f796a9c5-dirty
Built:        Mon Jul 19 15:15:03 2021
OS/Arch:      linux/amd64

Output of podman info --debug:

host:
  arch: amd64
  buildahVersion: 1.22.0-dev
  cgroupControllers:
  - cpuset
  - cpu
  - cpuacct
  - blkio
  - memory
  - devices
  - freezer
  - net_cls
  - perf_event
  - net_prio
  - hugetlb
  - pids
  - rdma
  cgroupManager: systemd
  cgroupVersion: v1
  conmon:
    package: conmon-2.0.26-1.module+el8.4.0+10607+f4da7515.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.0.26, commit: b883692702312720058141f16b6002ab26ead2e7'
  cpus: 8
  distribution:
    distribution: '"rhel"'
    version: "8.4"
  eventLogger: file
  hostname: flex-vm-02.dc2.ros2100.veritas.com
  idMappings:
    gidmap: null
    uidmap: null
  kernel: 4.18.0-305.el8.x86_64
  linkmode: dynamic
  memFree: 10512580608
  memTotal: 33511845888
  ociRuntime:
    name: runc
    package: runc-1.0.0-70.rc92.module+el8.4.0+10607+f4da7515.x86_64
    path: /usr/bin/runc
    version: 'runc version spec: 1.0.2-dev'
  os: linux
  remoteSocket:
    exists: true
    path: /run/podman/podman.sock
  security:
    apparmorEnabled: false
    capabilities: CAP_NET_RAW,CAP_CHOWN,CAP_DAC_OVERRIDE,CAP_FOWNER,CAP_FSETID,CAP_KILL,CAP_NET_BIND_SERVICE,CAP_SETFCAP,CAP_SETGID,CAP_SETPCAP,CAP_SETUID,CAP_SYS_CHROOT
    rootless: false
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: true
  serviceIsRemote: false
  slirp4netns:
    executable: ""
    package: ""
    version: ""
  swapFree: 16924012544
  swapTotal: 16924012544
  uptime: 20h 16m 54.88s (Approximately 0.83 days)
registries:
  search:
  - registry.access.redhat.com
  - registry.redhat.io
  - docker.io
store:
  configFile: /etc/containers/storage.conf
  containerStore:
    number: 2
    paused: 0
    running: 1
    stopped: 1
  graphDriverName: overlay
  graphOptions:
    overlay.mountopt: nodev,metacopy=on
  graphRoot: /var/lib/containers/storage
  graphStatus:
    Backing Filesystem: xfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "true"
  imageStore:
    number: 2
  runRoot: /run/containers/storage
  volumePath: /var/lib/containers/storage/volumes
version:
  APIVersion: 3.3.0-dev
  Built: 1626722103
  BuiltTime: Mon Jul 19 15:15:03 2021
  GitCommit: 6150f039365eafa00ba88382c3343769f796a9c5-dirty
  GoVersion: go1.16.5
  OsArch: linux/amd64
  Version: 3.3.0-dev

Package info (e.g. output of rpm -q podman or apt list podman):

Private build from podman main branch
runc-1.0.0-70.rc92.module+el8.4.0+10607+f4da7515.x86_6

Have you tested with the latest version of Podman and have you checked the Podman Troubleshooting Guide? (https://github.com/containers/podman/blob/master/troubleshooting.md)

Yes

Additional environment details (AWS, VirtualBox, physical, etc.):
VMware VM

@openshift-ci openshift-ci bot added the kind/bug Categorizes issue or PR as related to a bug. label Jul 20, 2021
@rhatdan
Copy link
Member

rhatdan commented Jul 21, 2021

@adrianreber PTAL

@adrianreber
Copy link
Collaborator

@vikas-goel Can you upload the dump.log file mentioned in the error message?

@vikas-goel
Copy link
Contributor Author

@vikas-goel Can you upload the dump.log file mentioned in the error message?

Already attached in the result section.

@adrianreber
Copy link
Collaborator

Ah, haven't seen it. Thanks. So CRIU says:

(00.348574) Error (criu/mount.c:663): mnt: 983:./usr/share/zoneinfo/UTC doesn't have a proper root mount

Never seen that one before. How did you create the container? I would be interested to be able to reproduce this.

@vikas-goel
Copy link
Contributor Author

The container was created using docker.

@adrianreber
Copy link
Collaborator

I meant how did you start the container. Can you share the podman run command line?

@adrianreber
Copy link
Collaborator

And maybe also the Dockerfile?

@adrianreber
Copy link
Collaborator

Ah, I think I was able to reproduce it:

$ podman run --tz=CET -d quay.io/adrianreber/wildfly-hello
$ podman container checkpoint -l --export=/tmp/test.tar
2021-07-21T15:53:17.000221741Z: CRIU checkpointing failed -52
Please check CRIU logfile /var/lib/containers/storage/overlay-containers/038a3a3c9474cdc74fecd0c46b3249ddab3a3b89129750007be2c8d1ecc0d93b/userdata/dump.log

Error: `/usr/bin/crun checkpoint --image-path /var/lib/containers/storage/overlay-containers/038a3a3c9474cdc74fecd0c46b3249ddab3a3b89129750007be2c8d1ecc0d93b/userdata/checkpoint --work-path /var/lib/containers/storage/overlay-containers/038a3a3c9474cdc74fecd0c46b3249ddab3a3b89129750007be2c8d1ecc0d93b/userdata 038a3a3c9474cdc74fecd0c46b3249ddab3a3b89129750007be2c8d1ecc0d93b` failed: exit status 1

Did you use --tz?

Looking at the timezone mount I see in the container:

tmpfs on /usr/share/zoneinfo/UTC type tmpfs (rw,seclabel,size=1172048k,nr_inodes=819200,mode=755,inode64)

But I do not see that mount mentioned in the config.json of the container. For CRIU to be able to checkpoint external mounts they need to be listed in config.json. I see, however, following line in config.json:

    {
      "destination": "/etc/localtime",
      "type": "bind",
      "source": "/var/run/containers/storage/overlay-containers/038a3a3c9474cdc74fecd0c46b3249ddab3a3b89129750007be2c8d1ecc0d93b/userdata/localtime",
      "options": [
        "bind",
        "rprivate"
      ]
    },

@rhatdan do you have insights how timezone mounts work. Why aren't they listed in config.json?

@vikas-goel
Copy link
Contributor Author

vikas-goel commented Jul 21, 2021

I started the container using docker-compose. Not sure if docker-compose is playing a role there as I didn't specify time zone info in the compose file. However, I do see the file mounted inside the container, as you mentioned. I did specify bind mount /etc/localtime which is a symlink to ../usr/share/zoneinfo/America/New_York on the host.

/dev/mapper/rhel_flex--vm--02-root on /usr/share/zoneinfo/UTC type xfs (ro,relatime,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota)

Attaching the podman inspect log in case it helps.
tme-mas-01-inspect.txt

@mheon
Copy link
Member

mheon commented Jul 22, 2021

We handle --tz mounts similar to /etc/hosts and /etc/resolv.conf - Podman creates a copy of the host content to be mounted into the container (every time the container starts), then makes a bind-mount for it. So if /etc/hosts / /etc/resolv.conf require special handling for checkpoint/restore we will need to add that for --tz as well (and probably add some comments to the code so we know to do this when we add other mounts like this)

@adrianreber
Copy link
Collaborator

/etc/hosts and /etc/resolv.conf are listed in config.json:

    {
      "destination": "/etc/resolv.conf",
      "type": "bind",
      "source": "/var/run/containers/storage/overlay-containers/d7d01eb1e7cecff359ec9efbcaeb7ac02ff71089f46362854a5495b17df683fe/userdata/resolv.conf",
      "options": [
        "bind",
        "rprivate"
      ]
    },
    {
      "destination": "/etc/hosts",
      "type": "bind",
      "source": "/var/run/containers/storage/overlay-containers/d7d01eb1e7cecff359ec9efbcaeb7ac02ff71089f46362854a5495b17df683fe/userdata/hosts",
      "options": [
        "bind",
        "rprivate"
      ]
    },

I do not see the timezone mounts in config.json.

@vikas-goel
Copy link
Contributor Author

vikas-goel commented Jul 22, 2021

Apart from time zone issue, there seems to be another one.

I disabled the /etc/localtime bind mount and tried checkpoint again. It failed in a different code path.

(00.157527) fsnotify:   Handle 0x4e:0x217ba5 is openable
(00.157533) fsnotify:           Trying via mntid 1156 root / ns_mountpoint @./run (53)
(00.157539) fsnotify:                   link as run
(00.157543) fsnotify:                   openable (inode match) as run
(00.157545) fsnotify:   Dumping /run as path for handle
(00.157547) fsnotify: wd: wd 0x000001 s_dev 0x000048 i_ino        0x82a0873 mask 0x000800
(00.157548) fsnotify:   [fhandle] bytes 0x000008 type 0x000001 __handle 0x000000082a0873:0000000000000000
(00.157550) fsnotify: Opening fhandle 48:82a0873...
(00.157560) Warn  (criu/fsnotify.c:288): fsnotify:      Handle 0x48:0x82a0873 cannot be opened
(00.157562) irmap: Resolving 48:82a0873 path
(00.157563) irmap:      Found /. in cache
(00.157565) fsnotify:   Dumping /. as path for handle
(00.157566) fsnotify: id 0x000028 flags 0x000800
(00.157581) 469046 fdinfo 24: pos:                0 flags:           504002/0x1
(00.157589) Dumping path for 24 fd via self 36 [/run/dmeventd-server]
(00.157594) Dumping fifo 36 with id 0x29 pipe_id 0x218a19
(00.157596) Dumping data from pipe 0x218a19 fd 36
(00.157639) 469046 fdinfo 25: pos:                0 flags:           504002/0x1
(00.157647) Dumping path for 25 fd via self 37 [/run/dmeventd-client]
(00.157651) Dumping fifo 37 with id 0x2b pipe_id 0x218a1a
(00.157653) Dumping data from pipe 0x218a1a fd 37
(00.157674) 469046 fdinfo 26: pos:                0 flags:             4002/0x1
(00.157693) timerfd: Dumping id 0x2d clockid 1 it_value(169, 889561502) it_interval(0, 0)
(00.157705) 469046 fdinfo 27: pos:                0 flags:                2/0x1
(00.157712) sockets: Searching for socket 0x218a27 family 16
(00.157725) sockets: No filter for socket
(00.157738) 469046 fdinfo 28: pos:                0 flags:                2/0x1
(00.157744) sockets: Searching for socket 0x219098 family 1
(00.157761) unix: unix: Dropping path /var/run/nscd/socket for unlinked bound sk 0x4e.2198364 real 0x4e.2199705
(00.157774) sockets: No filter for socket
(00.157775) unix: Dumping unix socket at 28
(00.157776) unix:       Dumping: ino 2199704 peer_ino 0 family    1 type    2 state  7 name /var/run/nscd/socket
(00.157780) unix:       Dumped: id 0x2f ino 2199704 peer 0 type 2 state 7 name 21 bytes
(00.157794) 469046 fdinfo 29: pos:                0 flags:             4000/0x1
(00.157817) fsnotify: wd: wd 0x000003 s_dev 0x000048 i_ino        0x824f9bb mask 0x000d84
(00.157819) fsnotify:   [fhandle] bytes 0x000008 type 0x000001 __handle 0x0000000824f9bb:0000000000000000
(00.157821) fsnotify: Opening fhandle 48:824f9bb...
(00.157829) Warn  (criu/fsnotify.c:288): fsnotify:      Handle 0x48:0x824f9bb cannot be opened
(00.157831) irmap: Resolving 48:824f9bb path
(00.157833) irmap: Scanning /etc hint
(00.157844) irmap: Scanning /var/spool hint
(00.157846) irmap: Scanning /var/log hint
(00.157848) irmap: Scanning /usr/share/dbus-1/system-services hint
(00.157849) irmap: Scanning /var/lib/polkit-1/localauthority hint
(00.157851) irmap: Scanning /usr/share/polkit-1/actions hint
(00.157852) irmap: Scanning /lib/udev hint
(00.157855) irmap: Scanning /. hint
(00.157856) irmap: Scanning /no-such-path hint
(00.157857) irmap: Refresh stat for /no-such-path
(00.157945) Error (criu/irmap.c:86): irmap: Can't stat /no-such-path: No such file or directory
(00.157950) Error (criu/fsnotify.c:291): fsnotify:      Can't dump that handle
(00.157968) ----------------------------------------
(00.157981) Error (criu/cr-dump.c:1351): Dump files (pid: 469046) failed with -1
(00.158008) Waiting for 469046 to trap
(00.158146) Daemon 469046 exited trapping
(00.158179) Sent msg to daemon 3 0 0
(00.158196) Force no-breakpoints restore

@adrianreber
Copy link
Collaborator

You should open an issue at CRIU about this as this is not really a podman problem and chances are much higher someone knows why it fails if you directly take it to CRIU.

@mheon
Copy link
Member

mheon commented Jul 22, 2021

Localtime should definitely be a bind mount - the same code that manages resolv.conf and hosts was extended to manage it as well. Very surprised it's not in the OCI spec JSON

@vikas-goel
Copy link
Contributor Author

You should open an issue at CRIU about this as this is not really a podman problem and chances are much higher someone knows why it fails if you directly take it to CRIU.

I can do that. I see some threads on same issue. One of them points to root cause that overay FS does not implement inotify interfaces.
checkpoint-restore/criu#1187 (comment)
libuv/libuv#1201

Do you happen to know if that is still the case?

@adrianreber
Copy link
Collaborator

Localtime should definitely be a bind mount - the same code that manages resolv.conf and hosts was extended to manage it as well. Very surprised it's not in the OCI spec JSON

So if a timezone is specified there is an entry for /etc/localtime:

    {
      "destination": "/etc/localtime",
      "type": "bind",
      "source": "/var/run/containers/storage/overlay-containers/038a3a3c9474cdc74fecd0c46b3249ddab3a3b89129750007be2c8d1ecc0d93b/userdata/localtime",
      "options": [
        "bind",
        "rprivate"
      ]
    },

But I do not see /etc/localtime mounted in the container. I see:

tmpfs on /usr/share/zoneinfo/UTC type tmpfs (rw,seclabel,size=1172048k,nr_inodes=819200,mode=755,inode64)

The question is, why is /etc/localtime mentioned in config.json but not mounted?
Why is /usr/share/zoneinfo/UTC mounted but not mentioned in config.json?

CRIU cannot checkpoint a mount if it does not know how to restore it. If /usr/share/zoneinfo/UTC is mounted it should be mentioned in config.json.

@adrianreber
Copy link
Collaborator

You should open an issue at CRIU about this as this is not really a podman problem and chances are much higher someone knows why it fails if you directly take it to CRIU.

I can do that. I see some threads on same issue. One of them points to root cause that overay FS does not implement inotify interfaces.
checkpoint-restore/criu#1187 (comment)
libuv/libuv#1201

Do you happen to know if that is still the case?

I am not aware that it has been resolved. It seems your container cannot be checkpointed. But important to know, your application is probably not working correctly in the container anyway if it relies on inotify which does not work on overlayfs. You could try the graphdriver vfs to see if the checkpointing works then.

@Snorch
Copy link

Snorch commented Jul 26, 2021

You should open an issue at CRIU about this as this is not really a podman problem and chances are much higher someone knows why it fails if you directly take it to CRIU.

I can do that. I see some threads on same issue. One of them points to root cause that overay FS does not implement inotify interfaces.
checkpoint-restore/criu#1187 (comment)
libuv/libuv#1201

Do you happen to know if that is still the case?

I am not aware that it has been resolved. It seems your container cannot be checkpointed. But important to know, your application is probably not working correctly in the container anyway if it relies on inotify which does not work on overlayfs. You could try the graphdriver vfs to see if the checkpointing works then.

Hi, all!

(00.157794) 469046 fdinfo 29: pos:                0 flags:             4000/0x1
(00.157817) fsnotify: wd: wd 0x000003 s_dev 0x000048 i_ino        0x824f9bb mask 0x000d84
(00.157819) fsnotify:   [fhandle] bytes 0x000008 type 0x000001 __handle 0x0000000824f9bb:0000000000000000
(00.157821) fsnotify: Opening fhandle 48:824f9bb...
(00.157829) Warn  (criu/fsnotify.c:288): fsnotify:      Handle 0x48:0x824f9bb cannot be opened

First thing I'd like to mention is that this error does not say anything about overlayfs. This error can be about any other virtual FS which does not support resolving file handles. You should check on your node which device is 0x48(72) to be sure... JFYI you should look for device id in format " 0:72 " in /proc/self/mountinfo just after you got an error.

Second thing is that overlayfs supports simple inotifys fine, so your app is not affected. But to dump inotifys overlayfs should provide valid fhandle for it in proc, and this can only happen if overlayfs has:

Preserve hardlinks (index=on) (v4.13)
NFS export (nfs_export=on) (v4.16)

You should enable those options on overlayfs (likely via podman) to be able to c/r inotifies on it.

@vikas-goel
Copy link
Contributor Author

vikas-goel commented Jul 26, 2021

Thanks for your comments, @Snorch . I didn't find any device in format "0:72".

# getenforce
Permissive
# podman container checkpoint tme-mas-01
ERRO[0000] container is not destroyed
ERRO[0000] criu failed: type NOTIFY errno 0
log file: /var/lib/containers/storage/overlay-containers/b00505aa652d72bb878fcb6225b2a6b37169cfb73c504900ce456e5d1e1af1eb/userdata/dump.log
Error: `/usr/bin/runc checkpoint --image-path /var/lib/containers/storage/overlay-containers/b00505aa652d72bb878fcb6225b2a6b37169cfb73c504900ce456e5d1e1af1eb/userdata/checkpoint --work-path /var/lib/containers/storage/overlay-containers/b00505aa652d72bb878fcb6225b2a6b37169cfb73c504900ce456e5d1e1af1eb/userdata b00505aa652d72bb878fcb6225b2a6b37169cfb73c504900ce456e5d1e1af1eb` failed: exit status 1
# grep -i error /var/lib/containers/storage/overlay-containers/b00505aa652d72bb878fcb6225b2a6b37169cfb73c504900ce456e5d1e1af1eb/userdata/dump.log
(00.145329) irmap: Refresh stat for /var/log/nginx/error.log
(00.148400) Error (criu/irmap.c:86): irmap: Can't stat /no-such-path: No such file or directory
(00.148408) Error (criu/fsnotify.c:291): fsnotify:      Can't dump that handle
(00.148450) Error (criu/cr-dump.c:1351): Dump files (pid: 1092012) failed with -1
(00.159442) Error (criu/cr-dump.c:1768): Dumping FAILED.
# grep "0:72" /proc/self/mountinfo
#

Is this concerning?

@vikas-goel
Copy link
Contributor Author

vikas-goel commented Jul 26, 2021

I turned on overlay module's index and nfs_export parameters and tried again as suggested by @Snorch . This time I received a different error.

# cat /sys/module/overlay/parameters/{index,nfs_export}
Y
Y
# <create container tme-mas-01>
# podman container checkpoint tme-mas-01
ERRO[0000] container is not destroyed
ERRO[0000] criu failed: type NOTIFY errno 0
log file: /var/lib/containers/storage/overlay-containers/0b8cc37a16d46f2a80d9c56e18f24cf8c633c17e491f5933d6ba072ddff9068c/userdata/dump.log
Error: `/usr/bin/runc checkpoint --image-path /var/lib/containers/storage/overlay-containers/0b8cc37a16d46f2a80d9c56e18f24cf8c633c17e491f5933d6ba072ddff9068c/userdata/checkpoint --work-path /var/lib/containers/storage/overlay-containers/0b8cc37a16d46f2a80d9c56e18f24cf8c633c17e491f5933d6ba072ddff9068c/userdata 0b8cc37a16d46f2a80d9c56e18f24cf8c633c17e491f5933d6ba072ddff9068c` failed: exit status 1
# grep -i error /var/lib/containers/storage/overlay-containers/0b8cc37a16d46f2a80d9c56e18f24cf8c633c17e491f5933d6ba072ddff9068c/userdata/dump.log
(00.380034) Dumping path for -3 fd via self 14 [/usr/lib64/libgpg-error.so.0.10.0]
(00.385907) Error (criu/sk-unix.c:430): unix: Unix socket 5237320 without peer 15532
(00.386037) Error (criu/cr-dump.c:1351): Dump files (pid: 1104632) failed with -1
(00.397813) Error (criu/cr-dump.c:1768): Dumping FAILED.
#

The complete dump.log is dump.log

@vikas-goel
Copy link
Contributor Author

vikas-goel commented Jul 26, 2021

In order to bypass the socket error as seen in the previous comment, I tried taking checkpoint with memory only. Received another error.

# podman container checkpoint --leave-running --pre-checkpoint tme-mas-01
ERRO[0000] criu failed: type PRE_DUMP errno 0
log file: /var/lib/containers/storage/overlay-containers/534f89ad59063715cd8226042006059629663008d6754b244686e795cbc94cc7/userdata/dump.log
Error: `/usr/bin/runc checkpoint --image-path /var/lib/containers/storage/overlay-containers/534f89ad59063715cd8226042006059629663008d6754b244686e795cbc94cc7/userdata/pre-checkpoint --work-path /var/lib/containers/storage/overlay-containers/534f89ad59063715cd8226042006059629663008d6754b244686e795cbc94cc7/userdata --leave-running --pre-dump 534f89ad59063715cd8226042006059629663008d6754b244686e795cbc94cc7` failed: exit status 1
# cat /var/lib/containers/storage/overlay-(00.312325) fsnotify: Opening fhandle 33:810021fb00000000...
...
(00.312166) irmap: Running irmap pre-dump
(00.312169) irmap:      checking 33:4089123
(00.312172) fsnotify: Opening fhandle 33:810021fb00000000...
(00.312204) fsnotify:   Handle 0x33:0x4089123 is openable
(00.312214) fsnotify:           Trying via mntid 942 root / ns_mountpoint @./ (13)
(00.312237) fsnotify:                   link as var/spool/cron
(00.312253) fsnotify:                   openable (inode match) as var/spool/cron
(00.312255) fsnotify:   Dumping /var/spool/cron as path for handle
(00.312259) irmap: Irmap cache 33:4089123 -> /var/spool/cron
(00.312269) irmap:      checking 33:c04892e
(00.312271) fsnotify: Opening fhandle 33:810021fb00000000...
(00.312286) fsnotify:   Handle 0x33:0xc04892e is openable
(00.312295) fsnotify:           Trying via mntid 942 root / ns_mountpoint @./ (13)
(00.312307) fsnotify:                   link as etc/cron.d
(00.312316) fsnotify:                   openable (inode match) as etc/cron.d
(00.312318) fsnotify:   Dumping /etc/cron.d as path for handle
(00.312321) irmap: Irmap cache 33:c04892e -> /etc/cron.d
(00.312323) irmap:      checking 33:c0351b8
(00.312325) fsnotify: Opening fhandle 33:810021fb00000000...
(00.312339) fsnotify:   Handle 0x33:0xc0351b8 is openable
(00.312348) fsnotify:           Trying via mntid 942 root / ns_mountpoint @./ (13)
(00.312359) fsnotify:                   link as etc/crontab
(00.312366) fsnotify:                   openable (inode match) as etc/crontab
(00.312368) fsnotify:   Dumping /etc/crontab as path for handle
(00.312371) irmap: Irmap cache 33:c0351b8 -> /etc/crontab
(00.312373) irmap:      checking 18:50442b
(00.312375) fsnotify: Opening fhandle 18:50442b60ff2158...
(00.312391) fsnotify:   Handle 0x18:0x50442b is openable
(00.312400) fsnotify:           Trying via mntid 959 root /containers/storage/overlay-containers/534f89ad59063715cd8226042006059629663008d6754b244686e795cbc94cc7/userdata/run/secrets ns_mountpoint @./run/secrets (13)
(00.312411) fsnotify:                   link as .
(00.312417) fsnotify:                   openable (inode don't match) as .
(00.312517) Error (criu/fsnotify.c:271): fsnotify: Can't find suitable path for handle (dev 0x18 ino 0x50442b): -2
(00.312526) Error (criu/irmap.c:359): irmap: Failed to resolve 18:50442b
(00.312540) Writing image inventory (version 1)
(00.312590) Error (criu/cr-dump.c:1570): Pre-dumping FAILED.
# 

@github-actions
Copy link

A friendly reminder that this issue had no activity for 30 days.

@rhatdan
Copy link
Member

rhatdan commented Aug 29, 2021

@vikas-goel Is this still an issue? @adrianreber Thoughts?

@vikas-goel
Copy link
Contributor Author

Yes, there are three issues I reported here. None of them seem to be resolved.

  1. Failure due to time zone
  2. Failure due to Unix socket
  3. Failure due to inode mismatch

@adrianreber
Copy link
Collaborator

Yes, there are three issues I reported here. None of them seem to be resolved.

1. Failure due to time zone

No one really answered why the timezone mount exists in the container without the corresponding entry in config.json. If there is a mount in a container and it is not listed in config.json checkpoint/restore will not work.

2. Failure due to Unix socket

3. Failure due to inode mismatch

This is probably a shortcoming of CRIU and it seems like you have an application which cannot be checkpointed. Can you try it with a simpler application to verify that it works at all.

@vikas-goel
Copy link
Contributor Author

The errors I am encountering look generic in nature that any application may have as requirements. I understand a simpler (bare minimum) application may not face the issues. But then the value of container checkpoint feature is defeated.

@mheon
Copy link
Member

mheon commented Aug 31, 2021

@adrianreber I ran locally and confirmed that there is a bind mount for /etc/localtime in the container - it's in the OCI spec.

@adrianreber
Copy link
Collaborator

If I do:

podman run --tz=CET -d quay.io/adrianreber/counter

I get following tmpfs mounts:

tmpfs /etc/hostname tmpfs rw,seclabel,size=1172048k,nr_inodes=819200,mode=755,inode64 0 0
tmpfs /usr/share/zoneinfo/Etc/UTC tmpfs rw,seclabel,size=1172048k,nr_inodes=819200,mode=755,inode64 0 0
tmpfs /run/.containerenv tmpfs rw,seclabel,size=1172048k,nr_inodes=819200,mode=755,inode64 0 0
tmpfs /run/secrets tmpfs rw,seclabel,size=1172048k,nr_inodes=819200,mode=755,inode64 0 0
tmpfs /etc/hosts tmpfs rw,seclabel,size=1172048k,nr_inodes=819200,mode=755,inode64 0 0

All files are mentioned in config.json. Only /usr/share/zoneinfo/Etc/UTC is mounted from .../userdata/localtime without an entry in config.json.

@mheon
Copy link
Member

mheon commented Aug 31, 2021

From a container I just created using --tz=local:

    {
      "destination": "/etc/localtime",
      "type": "bind",
      "source": "/run/user/1000/containers/overlay-containers/758caad223b8dae2f08268a995035f0cca56f16a3cdbfb262cd3d5492d95a036/userdata/localtime",
      "options": [
        "bind",
        "rprivate"
      ]
    },

@mheon
Copy link
Member

mheon commented Aug 31, 2021

I can verify that the results are effectively identical when I use --tz=CET. There is a bind mount in config.json for /etc/localtime.

It looks like this is a symlink in the container to ../usr/share/zoneinfo/Etc/UTC. Best guess is that the OCI runtime followed the link and created the bind-mount there.

@giuseppe This sounds like it could be a bug in crun - following the symlink in the container's rootfs, instead of creating the bind-mount directly over it, seems incorrect?

@giuseppe
Copy link
Member

@giuseppe This sounds like it could be a bug in crun - following the symlink in the container's rootfs, instead of creating the bind-mount directly over it, seems incorrect?

I don't think it is possible to create a bind mount on a symlink.

If you use a symlink as target for mount, the kernel will resolve it. The runtime resolves the symlink to avoid it can point to paths outside the rootfs. crun uses openat2 to resolve it inside the chroot. .. at the root directory has no effect, e.g. a symlink /a/b/symlink like ../../../../foo will be resolved to /foo.

@Snorch
Copy link

Snorch commented Sep 1, 2021

If I understand the above correctly, that's what happens:

Container runtime creates external bind-mount for a container and it's target path is a symlink and external bind-mount is created in the symlink resolved path instead which is different to target path.

We actually have a problem here, because current CRIU mount engine can't understand that this mount with different mountpoint is external (because we tell criu about external mounts by mountpoint).

Same happens if the container user would move external bind-mount to different mountpoint (or bind to other mountpoint and umount target mountpoint) inside container.

I've already stated this problem here checkpoint-restore/criu#1396 and proposed a possible solution. Not sure if it will be done soon though, I would rather do it after switch to mount-v2.

@github-actions
Copy link

github-actions bot commented Oct 2, 2021

A friendly reminder that this issue had no activity for 30 days.

@rhatdan
Copy link
Member

rhatdan commented Oct 4, 2021

@Snorch Anything happening with this?

@github-actions
Copy link

github-actions bot commented Nov 4, 2021

A friendly reminder that this issue had no activity for 30 days.

@rhatdan
Copy link
Member

rhatdan commented Nov 4, 2021

No movement on this in the last month. I am not sure what has to change in Podman, or if this is just issues with CRIU.

@adrianreber
Copy link
Collaborator

I also think there is nothing Podman can do here. The information in config.json does not match the actual mount, so either the runtime must mount it differently or CRIU needs to handle it differently. Definitely not something Podman can solve.

@github-actions
Copy link

github-actions bot commented Dec 5, 2021

A friendly reminder that this issue had no activity for 30 days.

@rhatdan
Copy link
Member

rhatdan commented Dec 7, 2021

Since we have not heard further and we don't believe Podman is doing anything wrong, closing.

@TahaW863
Copy link

TahaW863 commented Jun 5, 2023

Please run podman with "sudo podman system service --time=0 unix:///tmp/podman.sock"
then try creating podman container with root permissions.
then try checkpointing

# sudo curl -XPOST --unix-socket /tmp/podman.sock  -H content-type:application/json  http://d/v4.0.0/libpod/containers/{CONTAINER_ID OR NAME}/checkpoint

@github-actions github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Sep 4, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Sep 4, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. stale-issue
Projects
None yet
Development

No branches or pull requests

7 participants