Well, this is happening at the mock layer, so I'd start there. The binary data is also in mock_output.log

Could it be related to nspawn instead of old chroot behaviour (log seems to be using that version)?

Not specific to failed runroots. Here is a successful one with the output
https://koji.fedoraproject.org/koji/taskinfo?taskID=20246586

This one runs a different command, and does not have the output
https://koji.fedoraproject.org/koji/taskinfo?taskID=20245317

So this may be specific to pungi-make-ostree

My random guess is that the command inside the chroot has a surviving process that is somehow spewing this output

https://kojipkgs.fedoraproject.org//work/tasks/6447/20246447/mock_output.log
https://kojipkgs.fedoraproject.org//work/tasks/6586/20246586/mock_output.log
https://kojipkgs.fedoraproject.org//work/tasks/3655/20243655/mock_output.log

All of these seems to be emiting garbe in same point after 'Updating ref' line from ostree?

The Updating ref is the last thing that should be printed.

I have only seen this for the tasks running pungi-make-ostree, and it's the only thing that uses new_chroot = True. So that could be related as well.

I'd like to see a simpler case. Since I no longer have admin access in Fedora's koji, can someone please try this there:

koji runroot --new-chroot --task-id --channel compose f27-build x86_64 echo HELLO WORLD

And post the output and task link here, please?

When I do this on my local instance, I do not get any binary output.

OTOH, it seems that the runroot output is not getting captured properly with --new-chroot. No runroot.log, no "HELLO WORLD" shown on client end.

Well, I figured out the no runroot.log problem at least.

With --new-chroot, /tmp is set up as a tmpfs mount, which does not persist. The runroot plugin writes the command output to /tmp/runroot.log. When koji later looks for that file it finds nothing. Hence no runroot.log.

I don't see how this could be causing the binary output, but it currently prevents us from determining whether this binary output is coming from the runroot command of from mock itself. (my money is on the former)

PR #499 should fix the runroot.log issue

The closest I can get to replicating this so far is to duplicate the mock environment

# kdev koji mock-config --task 20246586 -o /tmp/mikem.cfg

(mock config edited to point to latest repo, and copied into /etc/mock)

Generate the chroot:

# sudo -u kojibuilder /usr/bin/mock -r mikem --dnf --init

I can't mount Fedora's volume locally, so I downloaded key files from https://kojipkgs.fedoraproject.org/compose/cd/fedora-atomic/ and copied them into the chroot. E.g.

# curl -O https://kojipkgs.fedoraproject.org/compose/cd/fedora-atomic/fedora-atomic-docker-host.json
# sudo -u kojibuilder /usr/bin/mock -r mikem --dnf --no-clean --new-chroot --copyin fedora-atomic-docker-host.json /builddir

(repeated for several files)

And finally, running a hopefully analogous mock command:

# sudo -u kojibuilder /usr/bin/mock -r mikem --dnf --no-clean --new-chroot --chroot 'pungi-make-ostree tree --log-dir=/builddir/foobar --treefile=/builddir/fedora-atomic-docker-host.json --repo=https://kojipkgs.fedoraproject.org/atomic-cd/'

I'm doing this on f24. I'm not getting any binary output. Of course, my replication is not perfect, but perhaps someone else can improve upon my approach.

Again, really doubting that anything in Koji is contributing. Just trying to help debug,. I know issues inside buildroots can get really tricky.

I don't have access to prod koji, so can't test there. I did run the hello world test in stage a couple times and it does not print the binary data.

I tried replicating in mock locally as well and so far did not have any success with getting the binary output to show up.

If feasible, it would be nice to get the fix from PR #499 onto Fedora's koji. It would help narrow things down slightly.

The Fedora builder is an F25 box, with mock-1.3.4-1.fc25.noarch

don't know if this helps or not but here is another example with binary data in the log: https://koji.fedoraproject.org/koji/taskinfo?taskID=20246448

it is still an ostree task, but ostree workstation vs atomic host

https://koji.fedoraproject.org/koji/taskinfo?taskID=20246448

Also, it's f26-build vs f27-build. Analogous versions of ostree (disttag differs). Slightly different versions of rpm-ostree.

rpm-ostree-2017.6-3.fc26.x86_64
rpm-ostree-2017.6.67.g417a3d8-4.fc27.x86_64

Commit 14ec03f relates to this ticket

I don't know if that commit is in production or not, but here is another one where there is binary data in the logs: https://koji.fedoraproject.org/koji/taskinfo?taskID=21440499

I don't know if that commit is in production or not, but here is another one where there is binary data in the logs: https://koji.fedoraproject.org/koji/taskinfo?taskID=21440499

The PR I merged doesn't really address this issue, it would just help narrow down where the output is coming from.

Since this task doesn't have a runroot.log file, I assume that the Fedora infra has not applied the patch.

The PR I merged doesn't really address this issue, it would just help narrow down where the output is coming from.
Since this task doesn't have a runroot.log file, I assume that the Fedora infra has not applied the patch.

Any chance the logs here would help you?

Any chance the logs here would help you?
I assume the logs here

No, that's the output of pungi running the runroot command locally, not the output of the command actually being run inside the chroot (granted it should contain that output, but does not because of the issue that #499 fixes).

hey @mikem - back after a long absence we saw something similar again on 37252058 from one of the recent Fedora 31 composes. Do you think the data there indicates it is related to this issue? If os does it give us any more clues?

It no longer appears AFAIK