Hidden stdout/stderr and hack to make it visible

[Thomas Güttler]

What do you think about this?

I get this message from salt-ssh

---

      ID: apache
Function: pkg.installed
  Result: False
 Comment: Problem encountered installing package(s). Additional info follows:

          errors:
              - Running scope as unit: run-r62a347a4ff4d4aa398bd0b516ba4fb59.scope
                E: Sub-process /usr/bin/dpkg returned an error code (1)
 Started: 15:47:16.154590
Duration: 9726.732 ms
 Changes:   

How to get see the root of the problem?

I already used --log-level=all, but still can't see a meaningful error message.

I don't think that dpkg silently exists with an error code without printing some message on stdout/stderr.

I guess that salt-stack drops the important error message somewhere.

---------------------

I hacked together this wrapper. I moved the original /usr/bin/dpkg to /usr/bin/dpkg-orig:

#!/usr/bin/env python
import os
import sys
import datetime
import subx
import psutil
cmd=list(sys.argv)
cmd[0]='dpkg-orig'

def parents(pid=None):
    if pid==1:
        return '\n'
    if pid is None:
        pid = os.getpid()
    process = psutil.Process(pid)
    lines = [parents(process.ppid())]
    lines.append('Parent: %s' % ' '.join(process.cmdline()))
    return '\n'.join(lines)

result = subx.call(cmd, assert_zero_exit_status=False)
with open('/var/tmp/dpkg-calls.log', 'ab') as fd:
    fd.write('----------- %s\n' % (datetime.datetime.now()))
    fd.write('%s\n' % parents())
    fd.write('stdout:\n%s\n\n' % result.stdout)
    sys.stdout.write(result.stdout)
    fd.write('stderr:\n%s\n' % result.stderr)
    fd.write('ret: %s\n' % result.ret)
    sys.stderr.write(result.stderr)
sys.exit(result.ret)

Now I run salt-ssh again and searched for non zero "ret:" lines.

I found:

Parent: python2.7 /var/tmp/.root_dcdf8c_salt/salt-call --retcode-passthrough --local --metadata --out json -l quiet -c /var/tmp/.root_dcdf8c_salt -- state.pkg /var/tmp/.root_dcdf8c_salt/salt_state.tgz test=None pkg_sum=4c32dcc67f70b49ade14d34d610653a98eed3b9fc8418f2f1267886f1b37c5e1 hash_type=sha256
Parent: /usr/bin/apt-get -q -y -o DPkg::Options::=--force-confold -o DPkg::Options::=--force-confdef install openssl-foo-bar-aptguettler.cert
Parent: python /usr/bin/dpkg --force-confold --force-confdef --status-fd 67 --no-triggers --unpack --auto-deconfigure /var/cache/apt/archives/openssl-foo-bar-aptguettler.cert_1-2_all.deb

stdout:


stderr:
dpkg: error: unable to read filedescriptor flags for <package status and progress file descriptor>: Bad file descriptor

ret: 2

Now I know the problem is with the custom (non pulic) dpkg openssl-foo-bar-aptguettler.cert

It would be very kind, if salt-stack could tell me the real reason immediately the next time. It is not difficult, just don't hide stdout/stderr :-)

[Thomas Güttler]

https://serverfault.com/a/980744/90324

I hacked together this wrapper:

https://github.com/guettli/wrap_and_log_calls

Now I run salt-ssh again and searched for non zero "ret:" lines.

I found:

Parent: python2.7 /var/tmp/.root_dcdf8c_salt/salt-call --retcode-passthrough --local --metadata --out json -l quiet -c /var/tmp/.root_dcdf8c_salt -- state.pkg /var/tmp/.root_dcdf8c_salt/salt
_state.tgz test=None pkg_sum=7683cfdcaf0ef6b6c907889fab738da83b6f897fe02387251db02a25f541e4ca hash_type=sha256
Parent: /usr/bin/apt-get -q -y -o DPkg::Options::=--force-confold -o DPkg::Options::=--force-confdef install openssl-foo-bar-user.cert
Parent: python /usr/bin/dpkg --force-confold --force-confdef --status-fd 70 --no-triggers --unpack --auto-deconfigure /var/cache/apt/archives/openssl-foo-bar-user.cert_1-2_all.deb
stdout:
(Reading database ... 365773 files and directories currently installed.)
Preparing to unpack .../openssl-foo-bar-user.cert_1-2_all.deb ...
Unpacking openssl-foo-bar-user.cert (1-2) ...


stderr:
dpkg: error processing archive /var/cache/apt/archives/openssl-foo-bar-user.cert_1-2_all.deb (--unpack):
 trying to overwrite '/etc/ssl/server/foo-bar_user.pem', which is also in package server-certificates-user 2-2.1
dpkg-deb (subprocess): decompressing archive member: lzma write error: Broken pipe
dpkg-deb: error: <decompress> subprocess returned error exit status 2
Errors were encountered while processing:
 /var/cache/apt/archives/openssl-foo-bar-user.cert_1-2_all.deb

Now I know the problem is with the custom (non pulic) dpkg openssl-foo-bar-user.cert

It would be very kind, if salt-stack could tell me the real reason immediately the next time. It is not difficult, just don't hide stdout/stderr :-)