segmentation fault with podman and ocrmypdf

[Fulguritus]

I originally filed the issue in ocrmypdf: ocrmypdf/OCRmyPDF#889

Essentially, when doing

podman run --network none --rm -i jbarlow83/ocrmypdf:v13.2.0 --jobs 1 -l deu - - <tmp.pdf >out.pdf

the output hangs, and I see a segfault in conmon in dmesg:

[24408.182063] conmon[100696]: segfault at a8a000 ip 00007f025e26d9b5 sp 00007ffcc9e773e8 error 4 in libc.so.6[7f025e11e000+176000]
[24408.182091] Code: fd 74 5f 41 c5 fd 74 67 61 c5 ed eb e9 c5 dd eb f3 c5 cd eb ed c5 fd d7 cd 85 c9 75 48 48 83 ef 80 48 81 ea 80 00 00 00 77 cb <c5> fd 74 4f 01 c5 fd d7 c1 66 90 85 c0 75 5c 83 c2 40 0f 8f c3 00

Address within libc: 0x00007f025e26d9b5 - 0x7f025e11e000 = 0x14F9B5

$ addr2line -e /usr/lib/libc.so.6 -fCi 0x14F9B5
__GI_netname2host
:?

Running the same with log-level=debug, I see

DEBU[0270] Sending signal 2 to container b2799f12bc64a5e78947be68ec1c9c37daaa0de03a47c4de4531e87f32d7551f 
2022-01-10T16:46:08.000913691Z: open pidfd: No such process
ERRO[0275] No exit file for container b2799f12bc64a5e78947be68ec1c9c37daaa0de03a47c4de4531e87f32d7551f found: timed out waiting for file /run/user/1000/libpod/tmp/exits/b2799f12bc64a5e78947be68ec1c9c37daaa0de03a47c4de4531e87f32d7551f: internal libpod error 
ERRO[0275] Error forwarding signal 2 to container b2799f12bc64a5e78947be68ec1c9c37daaa0de03a47c4de4531e87f32d7551f: error sending signal to container b2799f12bc64a5e78947be68ec1c9c37daaa0de03a47c4de4531e87f32d7551f: `/usr/bin/crun kill b2799f12bc64a5e78947be68ec1c9c37daaa0de03a47c4de4531e87f32d7551f 2` failed: exit status 1 

Searching for this on the net brought up a potential fix on https://issueexplorer.com/issue/containers/conmon/251
Of this suggestion, only the first part made it into your code.

It is also worth noting that this does not happen all the time, but that is probably due to the output of ocrmypdf not being deterministic. Additionally, when this happens, podman logs contains some content that should go to stdout in stderr (and vice-versa).

This is executed on:

• Fedora 35
• conmon version 2.0.30
• podman version 3.4.4
• jbarlow83/ocrmypdf:v13.2.0
• The input file contains copyrighted material and can be made available to anyone looking into this (but I do not want to simply upload it here)

[Fulguritus]

Further details:

systemd-coredump[286424]: [🡕] Process 286401 (conmon) of user 1000 dumped core.
                                                
Found module linux-vdso.so.1 with build-id: 6761b48f74742f0a29da87e0229205606b993486
Found module libgpg-error.so.0 with build-id: 081975d0a3416374b4883b2f1639fd3c9df42390
Found module ld-linux-x86-64.so.2 with build-id: b43118df1fdb4c0aff150b6f8f926bccdec2a7f0
Found module libgcc_s.so.1 with build-id: 88564abce789aa42536da1247a57ff6062d61dcb
Found module libgcrypt.so.20 with build-id: 711d41580c5a8649a79a8430a985dac3e25b5ba2
Found module libcap.so.2 with build-id: 0214aa9cc6a8646eb9ec27ab7dda6a2219da6500
Found module liblz4.so.1 with build-id: fd02c4542a1ce1ad6c503b958447be1c37a4afee
Found module libzstd.so.1 with build-id: 0f6e793c8bbdb5bb5683c5b9e61aadfcb7a7454a
Found module liblzma.so.5 with build-id: 7fec53ce7cba9489f130c99cfd3ace82e9dde0ee
Found module libpcre.so.1 with build-id: fcbdb4731e50f20a47b62341a6841dd616fe495d
Found module libc.so.6 with build-id: 644dac2c66a6e0b32674f0ec71e7431bd0c06a63
Found module libseccomp.so.2 with build-id: d9e37e30e12bcd8de6d550fda9c874c8870067d9
Found module libsystemd.so.0 with build-id: e4996d7fd9705035bdd6072e68c9dc65647d7d1c
Found module libglib-2.0.so.0 with build-id: 3720108994016259cac8f61f174ea32513518152
Found module conmon with build-id: d185e6305296ab5c3539014320a9f083e49b214c
Stack trace of thread 286401:
#0  0x00007f6cbbc2a8b5 __memchr_avx2 (libc.so.6 + 0x17b8b5)
#1  0x00007f6cbbd38585 sd_journal_sendv (libsystemd.so.0 + 0x5f585)
#2  0x00007f6cbbd3a061 sd_journal_sendv_with_location (libsystemd.so.0 + 0x61061)
#3  0x0000000000405e10 write_journald (conmon + 0x5e10)
#4  0x0000000000406364 write_to_logs (conmon + 0x6364)
#5  0x00000000004093e9 read_stdio (conmon + 0x93e9)
#6  0x0000000000409445 stdio_cb (conmon + 0x9445)
#7  0x00007f6cbbe00130 g_main_context_dispatch (libglib-2.0.so.0 + 0x55130)
#8  0x00007f6cbbe55208 g_main_context_iterate.constprop.0 (libglib-2.0.so.0 + 0xaa208)
#9  0x00007f6cbbdff853 g_main_loop_run (libglib-2.0.so.0 + 0x54853)
#10 0x0000000000404d9a main (conmon + 0x4d9a)
#11 0x00007f6cbbadc560 __libc_start_call_main (libc.so.6 + 0x2d560)
#12 0x00007f6cbbadc60c __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x2d60c)
#13 0x0000000000405235 _start (conmon + 0x5235)

Stack trace of thread 286403:
#0  0x00007f6cbbbb473f __poll (libc.so.6 + 0x10573f)
#1  0x00007f6cbbe5519c g_main_context_iterate.constprop.0 (libglib-2.0.so.0 + 0xaa19c)
#2  0x00007f6cbbdfd933 g_main_context_iteration (libglib-2.0.so.0 + 0x52933)
#3  0x00007f6cbbdfd981 glib_worker_main (libglib-2.0.so.0 + 0x52981)
#4  0x00007f6cbbe2a842 g_thread_proxy (libglib-2.0.so.0 + 0x7f842)
#5  0x00007f6cbbb3ca87 start_thread (libc.so.6 + 0x8da87)
#6  0x00007f6cbbbc1640 __clone3 (libc.so.6 + 0x112640)

[Fulguritus]

Does this mean the issue is related to logging? By the nature of ocrmypdf, there will be (large) binary streams sent to STDOUT. Could it be that the construction of bufv in write_journald() cannot handle that kind of data or this amount of data? Could well be several (dozen/hundred) MBs of data in a scanned PDF.

[Fulguritus]

Is this related to #264?

[jess-sol]

I might be seeing a similar or the same issue:

podman run -ti centos:latest dd if=/dev/random of=/dev/stdout bs=1024 count=1024 > /dev/null # works
podman run -ti centos:latest dd if=/dev/random of=/dev/stdout bs=1024 count=10240 > /dev/null # fails

I get this error:

2022-02-01T17:32:05.000071504Z: open pidfd: No such process
ERRO[0084] No exit file for container 07f817432f8e9b45a5f2160cd5c56514a936cb509d9a39bfb587a7d5343fda14 found: timed out waiting for file /run/user/1000/libpod/tmp/exits/07f817432f8e9b45a5f2160cd5c56514a936cb509d9a39bfb587a7d5343fda14: internal libpod error
ERRO[0084] Error forwarding signal 28 to container 07f817432f8e9b45a5f2160cd5c56514a936cb509d9a39bfb587a7d5343fda14: error sending signal to container 07f817432f8e9b45a5f2160cd5c56514a936cb509d9a39bfb587a7d5343fda14: `/usr/bin/crun kill 07f817432f8e9b45a5f2160cd5c56514a936cb509d9a39bfb587a7d5343fda14 28` failed: exit status 1

And see this seg fault in dmesg

[ 2534.499889] conmon[37735]: segfault at 2187000 ip 00007f94c900f293 sp 00007ffd88aa3fc8 error 4 in libc.so.6[7f94c8f91000+176000]
[ 2534.503488] Code: d7 c3 85 c0 0f 85 ad 00 00 00 83 ea 10 0f 8e c4 00 00 00 66 0f 74 4f 30 66 0f d7 c1 85 c0 0f 85 a3 00 00 00 31 c0 c3 83 c2 20 <66> 0f 6f 07 66 0f 74 c1 66 0f d7 c0 85 c0 75 5d 83 ea 10 0f 86 94

Versions:

• Fedora 35 (versions 35.20220103.3.0 and 35.20220116.1.1)
• Conmon 2.0.30
• Podman 3.4.4

The error is from the built version of #264, same error with 2.0.30 too

[lyarwood]

I'm also seeing this when building a dev environment for the kubevirt project. For whatever reason part of the current process is to dump a 40mb binary file to the stdout of a container before piping it into a local file:

https://github.com/kubevirt/kubevirt/blob/f16dd510918daf5ff4653aeae055822cdd99ce4e/cluster-up/cluster/k8s-provider-common.sh#L125

• Fedora 35
• conmon-2.0.30-2.fc35.x86_64 (also reproduced with 2.1.0 from HEAD)

$ cd kubevirt
$ sudo make cluster-up
[..]
++ podman run --privileged --net=host --rm -v /root/podman.sock:/var/run/docker.sock -v /lib/modules/:/lib/modules/ quay.io/kubevirtci/gocli:2201311315-109a7c39 scp --prefix k8s-1.20 /usr/bin/kubectl -
^CERRO[0000] container not running                        
ERRO[0024] No exit file for container f3f07950d5da92bd1417f93683a8e9512f20f7055025df241c7c9bfb7b3abc48 found: timed out waiting for file /run/libpod/exits/f3f07950d5da92bd1417f93683a8e9512f20f7055025df241c7c9bfb7b3abc48: internal libpod error 
ERRO[0024] forwarding signal 2 to container f3f07950d5da92bd1417f93683a8e9512f20f7055025df241c7c9bfb7b3abc48: error sending signal to container f3f07950d5da92bd1417f93683a8e9512f20f7055025df241c7c9bfb7b3abc48: `/usr/bin/runc kill f3f07950d5da92bd1417f93683a8e9512f20f7055025df241c7c9bfb7b3abc48 2` failed: exit status 1 
make: *** [Makefile:138: cluster-up] Interrupt

$ sudo coredumpctl dump /usr/bin/conmon
           PID: 240263 (conmon)
           UID: 0 (root)
           GID: 0 (root)
        Signal: 11 (SEGV)
     Timestamp: Tue 2022-02-01 18:18:33 GMT (1min 30s ago)
  Command Line: /usr/bin/conmon --api-version 1 -c 33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef -u 33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef -r /usr/bin/runc -b /var/lib/containers/storage/overlay-containers/33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef/userdata -p /run/containers/storage/overlay-containers/33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef/userdata/pidfile -n sad_archimedes --exit-dir /run/libpod/exits --full-attach -s -l journald --log-level warning --runtime-arg --log-format=json --runtime-arg --log --runtime-arg=/run/containers/storage/overlay-containers/33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef/userdata/oci-log --conmon-pidfile /run/containers/storage/overlay-containers/33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef/userdata/conmon.pid --exit-command /usr/bin/podman --exit-command-arg --root --exit-command-arg /var/lib/containers/storage --exit-command-arg --runroot --exit-command-arg /run/containers/storage --exit-command-arg --log-level --exit-command-arg warning --exit-command-arg --cgroup-manager --exit-command-arg systemd --exit-command-arg --tmpdir --exit-command-arg /run/libpod --exit-command-arg --cni-config-dir --exit-command-arg /etc/cni/net.d/ --exit-command-arg --network-backend --exit-command-arg cni --exit-command-arg --runtime --exit-command-arg runc --exit-command-arg --storage-driver --exit-command-arg overlay --exit-command-arg --storage-opt --exit-command-arg overlay.mountopt=nodev,metacopy=on --exit-command-arg --events-backend --exit-command-arg journald --exit-command-arg container --exit-command-arg cleanup --exit-command-arg --rm --exit-command-arg 33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef
    Executable: /usr/bin/conmon
 Control Group: /machine.slice/libpod-conmon-33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef.scope
          Unit: libpod-conmon-33eb4a57fdebf699aec953f2059b8ce3e655f104138119d9711aae4bff5ee5ef.scope
         Slice: machine.slice
       Boot ID: e594f814d5684121ba8bfcd66c3a66e3
    Machine ID: 9225d3461f9d43c999f3ae7e7daa2109
      Hostname: lyarwood-laptop.usersys.redhat.com
       Storage: /var/lib/systemd/coredump/core.conmon.0.e594f814d5684121ba8bfcd66c3a66e3.240263.1643739513000000.zst (present)
     Disk Size: 103.6K
       Message: Process 240263 (conmon) of user 0 dumped core.
                
                Found module linux-vdso.so.1 with build-id: dd9f72d7bd194bdaf5264b45aa11ecb7d35396d6
                Found module libgpg-error.so.0 with build-id: 081975d0a3416374b4883b2f1639fd3c9df42390
                Found module ld-linux-x86-64.so.2 with build-id: 524f5518285687402d801b9c3b1e61d435e6780b
                Found module libgcc_s.so.1 with build-id: 88564abce789aa42536da1247a57ff6062d61dcb
                Found module libgcrypt.so.20 with build-id: 711d41580c5a8649a79a8430a985dac3e25b5ba2
                Found module libcap.so.2 with build-id: 0214aa9cc6a8646eb9ec27ab7dda6a2219da6500
                Found module liblz4.so.1 with build-id: fd02c4542a1ce1ad6c503b958447be1c37a4afee
                Found module libzstd.so.1 with build-id: 7984add4b0ab24869c30e19cfba3637ca295dd7b
                Found module liblzma.so.5 with build-id: 7fec53ce7cba9489f130c99cfd3ace82e9dde0ee
                Found module libpcre.so.1 with build-id: fcbdb4731e50f20a47b62341a6841dd616fe495d
                Found module libc.so.6 with build-id: d7e3e120ff5fafc298666927c6475567348588ef
                Found module libseccomp.so.2 with build-id: d9e37e30e12bcd8de6d550fda9c874c8870067d9
                Found module libsystemd.so.0 with build-id: b61753e8440ecf39624b3e37f855941c18a69e9b
                Found module libglib-2.0.so.0 with build-id: de8abd1f0b2c53eea9872862805b922e633f93e8
                Found module conmon with build-id: d185e6305296ab5c3539014320a9f083e49b214c
                Stack trace of thread 240263:
                #0  0x00007fa0d7ff1940 __memchr_avx2 (libc.so.6 + 0x17b940)
                #1  0x00007fa0d80ff5a5 sd_journal_sendv (libsystemd.so.0 + 0x5f5a5)
                #2  0x00007fa0d8101081 sd_journal_sendv_with_location (libsystemd.so.0 + 0x61081)
                #3  0x0000000000405e10 write_journald (conmon + 0x5e10)
                #4  0x0000000000406364 write_to_logs (conmon + 0x6364)
                #5  0x00000000004093e9 read_stdio (conmon + 0x93e9)
                #6  0x0000000000409445 stdio_cb (conmon + 0x9445)
                #7  0x00007fa0d81c705f g_main_context_dispatch (libglib-2.0.so.0 + 0x5505f)
                #8  0x00007fa0d821c298 g_main_context_iterate.constprop.0 (libglib-2.0.so.0 + 0xaa298)
                #9  0x00007fa0d81c6773 g_main_loop_run (libglib-2.0.so.0 + 0x54773)
                #10 0x0000000000404d9a main (conmon + 0x4d9a)
                #11 0x00007fa0d7ea3560 __libc_start_call_main (libc.so.6 + 0x2d560)
                #12 0x00007fa0d7ea360c __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x2d60c)
                #13 0x0000000000405235 _start (conmon + 0x5235)
                
                Stack trace of thread 240265:
                #0  0x00007fa0d7f7b79f __poll (libc.so.6 + 0x10579f)
                #1  0x00007fa0d821c22c g_main_context_iterate.constprop.0 (libglib-2.0.so.0 + 0xaa22c)
                #2  0x00007fa0d81c4853 g_main_context_iteration (libglib-2.0.so.0 + 0x52853)
                #3  0x00007fa0d81c48a1 glib_worker_main (libglib-2.0.so.0 + 0x528a1)
                #4  0x00007fa0d81f1772 g_thread_proxy (libglib-2.0.so.0 + 0x7f772)
                #5  0x00007fa0d7f03b1a start_thread (libc.so.6 + 0x8db1a)
                #6  0x00007fa0d7f88650 __clone3 (libc.so.6 + 0x112650)
Refusing to dump core to tty (use shell redirection or specify --output).

[jess-sol]

I'm attempting an install of Openshift and see it on the control nodes. The machine-config-daemon-pull service attempts to dump a binary file to stdout (to save as a local file) as well; and hangs due to this issue. I was attempting it in Proxmox, but see the same issue locally with KVM/QEMU.

EDIT: Looks like other projects are starting to work around the issue - openshift/machine-config-operator@cb76ecf