returned non-zero after checkpointed

[ghost]

process args = "sleep", "6000" in config.json

terminal 1> runc run root
terminal 2> runc checkpoint root
terminal 1> echo $?
terminal 1> 137

[mrunalp]

@qiancai Can you specify what version of criu are you using?

[ghost]

criu-2.3-2.el7.x86_64

[avagin]

Can you give more details about enviroment? What is a kernel version?
Could you run "strace -fo strace.log -s 256 runc checkpoint root" and show the strace.log file?

[ghost]

I upgraded the system including criu-2.12-1.el7, and it all work fine now.

[ghost]

I am sorry but I can still reproduce this. The system is the latest RHEL7.3.
BTW, the non-zero returned by "runc run root" after been checkpointed not from "runc checkpoint point", and the output is below. http://people.redhat.com/qcai/tmp/strace.log

[avagin]

10460 write(1023, "(00.888787) Dumping finished successfully\n", 42) = 42

"runc checkpoint root" returns 0, but than "runc run root" exits with non-zero code. Is it right?

Could you reproduce the problem, but run runc with --debug --log /tmp/runc.log options and show the /tmp/runc.log file?

[ghost]

Still reproducible on criu-3.9 and kernel-4.14.

terminal 1> runc --debug --log /tmp/runc.log run root
terminal 2> runc --debug --log /tmp/runc2.log checkpoint root
terminal 1> echo $?
terminal 1> 137

# cat /tmp/runc.log
time="2018-08-21T16:45:14-04:00" level=debug msg="process exited" pid=20514 status=137

# cat /tmp/runc2.log
time="2018-08-21T16:45:11-04:00" level=debug msg="Using CRIU with following args: [swrk 3]"
time="2018-08-21T16:45:11-04:00" level=debug msg="Using CRIU in VERSION mode"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU version: type:VERSION success:true version:<major:3 minor:9 > "
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU version: major:3 minor:9 "
time="2018-08-21T16:45:11-04:00" level=debug msg="Using CRIU 30900 at: criu"
time="2018-08-21T16:45:11-04:00" level=debug msg="Using CRIU with following args: [swrk 3]"
time="2018-08-21T16:45:11-04:00" level=debug msg="Using CRIU in DUMP mode"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ImagesDirFd with value 6"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option Pid with value 20514"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option LeaveRunning with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ExtUnixSk with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option TcpEstablished with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option EvasiveDevices with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ShellJob with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option FileLocks with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option LogLevel with value 4"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option LogFile with value dump.log"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option Ps with value "
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option NotifyScripts with value true"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option Root with value /root/rootfs"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ParentImg with value "
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option TrackMem with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option AutoDedup with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option WorkDirFd with value 5"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option LinkRemap with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option Veths with value []"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option CpuCap with value 4294967295"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ForceIrmap with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ExecCmd with value []"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ExtMnt with value [key:"/sys/fs/cgroup/systemd" val:"/sys/fs/cgroup/systemd" key:"/sys/fs/cgroup/freezer" val:"/sys/fs/cgroup/freezer" key:"/sys/fs/cgroup/net_cls,net_prio" val:"/sys/fs/cgroup/net_cls,net_prio" key:"/sys/fs/cgroup/pids" val:"/sys/fs/cgroup/pids" key:"/sys/fs/cgroup/cpu,cpuacct" val:"/sys/fs/cgroup/cpu,cpuacct" key:"/sys/fs/cgroup/hugetlb" val:"/sys/fs/cgroup/hugetlb" key:"/sys/fs/cgroup/blkio" val:"/sys/fs/cgroup/blkio" key:"/sys/fs/cgroup/perf_event" val:"/sys/fs/cgroup/perf_event" key:"/sys/fs/cgroup/cpuset" val:"/sys/fs/cgroup/cpuset" key:"/sys/fs/cgroup/memory" val:"/sys/fs/cgroup/memory" key:"/sys/fs/cgroup/devices" val:"/sys/fs/cgroup/devices" key:"/proc/kcore" val:"/dev/null" key:"/proc/timer_list" val:"/dev/null" key:"/proc/sched_debug" val:"/dev/null" key:"/dev/null" val:"/dev/null" key:"/dev/random" val:"/dev/random" key:"/dev/full" val:"/dev/full" key:"/dev/tty" val:"/dev/tty" key:"/dev/zero" val:"/dev/zero" key:"/dev/urandom" val:"/dev/urandom" ]"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ManageCgroups with value true"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option CgRoot with value []"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option RstSibling with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option InheritFd with value []"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option AutoExtMnt with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ExtSharing with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option ExtMasters with value false"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option SkipMnt with value []"
time="2018-08-21T16:45:11-04:00" level=debug msg="CRIU option EnableFs with value []"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option UnixSkIno with value []"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option ManageCgroupsMode with value IGNORE"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option GhostLimit with value 1048576"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option IrmapScanPaths with value []"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option External with value []"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option EmptyNs with value 0"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option JoinNs with value []"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option CgroupProps with value "
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option CgroupPropsFile with value "
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option CgroupDumpController with value []"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option FreezeCgroup with value /sys/fs/cgroup/freezer/root"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option Timeout with value 0"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option TcpSkipInFlight with value false"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option WeakSysctls with value false"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option LazyPages with value false"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option StatusFd with value 0"
time="2018-08-21T16:45:12-04:00" level=debug msg="CRIU option OrphanPtsMaster with value true"
time="2018-08-21T16:45:12-04:00" level=debug msg="notify: pre-dump
"
time="2018-08-21T16:45:12-04:00" level=debug msg="notify: network-lock
"
time="2018-08-21T16:45:14-04:00" level=debug msg="notify: post-dump
"

[rst0git]

moby/moby#21083

[avagin]

137 means that a container init process was killed by SIGKILL.

[avagin]

It is a normal behavior for a case when a container is checkpointed.