[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#765687: dpkg: no "Setting up $p ($v) ..." messages from apt-get -f install



Control: tags -1 - moreinfo + patch
Control: severity -1 serious

Hi,

> > The same problem with missing messages occurs in a clean jessie or sid pbuilder chroot.
> > In addition to the "Setting up" messages, also the "Processing triggers" messages seem to be missing sometimes (no testcase).
> > If I install something larger (e.g. libreoffice) I do get (some? all?) "Setting up" messages.

I haven't exactly figured out why "large" installations work and "small"
do not, but I have at least an idea what goes on and how to fix it:

This is partly a regression of a fix for kfreebsd where something
similar happened (although it was reported more as an issue showing in
a "stepped" output).

What apt does is creating a pseudo terminal to run various dpkg
instances in it. I have searched for other tools doing this, but all of
them seem to be creating one only to execute a program once…

Anyway, the first call is no problem, dpkg runs perfectly fine in the
pseudo terminal and the output is moved from the slave to the master.

Now, if the first call completes we prepare the next call by opening the
slave side again (reusing the same FD works for linux, but fails on
kfreebsd), which works for both, but on linux it still looses the
connection between master and slave 'sometimes' if this was the only
reference to the pseudo terminal. So what we do now is keeping
a reference to the slave open at all times, but do not use it, which
seems to make freebsd as well as linux happy again.
(Some more techno-babble can be found in the commit message.)

The rest of the attached git commit is reshuffling code to make sure
that we actually create a pseudo terminal if possible as we otherwise do
not populate the log in some cases while we absolutely should.


I am raising severity for this as we not only fail to keep a log, but we
potentially eat conffile and debconf prompts which is rather bad.



Best regards

David Kalnischkies
commit 150bdc9ca5d656f9fba94d37c5f4f183b02bd746
Author: David Kalnischkies <david@kalnischkies.de>
Date:   Tue Nov 18 00:59:39 2014 +0100

    fix PTY interaction on linux and kfreebsd
    
    We run dpkg on its own pty, so we can log its output and have our own
    output around it (like the progress bar), while also allowing debconf
    and configfile prompts to happen.
    
    In commit 223ae57d468fdcac451209a095047a07a5698212 we changed to
    constantly reopening the slave for kfreebsd. This has the sideeffect
    though that in some cases slave and master will lose their connection on
    linux, so that no output is passed along anymore. We fix this by having
    always an fd referencing the slave open (linux), but we don't use it
    (kfreebsd).
    
    Failing to get our PTY up and running has many (bad) consequences
    including (not limited to, nor all at ones or in any case) garbled ouput,
    no output, no logging, a (partial) mixture of the previous items, …
    This commit is therefore also reshuffling quiet a bit of the creation
    code to get especially the output part up and running on linux and the
    logging for kfreebsd.
    
    Note that the testcase tries to cover some cases, but this is an
    interactivity issue so only interactive usage can really be a good test.
    
    Closes: 765687

diff --git a/apt-pkg/deb/dpkgpm.cc b/apt-pkg/deb/dpkgpm.cc
index dd03eac..5938750 100644
--- a/apt-pkg/deb/dpkgpm.cc
+++ b/apt-pkg/deb/dpkgpm.cc
@@ -72,7 +72,8 @@ class pkgDPkgPMPrivate
 public:
    pkgDPkgPMPrivate() : stdin_is_dev_null(false), dpkgbuf_pos(0),
 			term_out(NULL), history_out(NULL),
-                        progress(NULL), master(-1), slave(NULL)
+			progress(NULL), tt_is_valid(false), master(-1),
+			slave(NULL), protect_slave_from_dying(-1)
    {
       dpkgbuf[0] = '\0';
    }
@@ -90,8 +91,10 @@ public:
 
    // pty stuff
    struct termios tt;
+   bool tt_is_valid;
    int master;
    char * slave;
+   int protect_slave_from_dying;
 
    // signals
    sigset_t sigmask;
@@ -1069,47 +1072,40 @@ void pkgDPkgPM::StartPtyMagic()
    }
 
    _error->PushToStack();
-   // if tcgetattr for both stdin/stdout returns 0 (no error)
-   // we do the pty magic
-   if (tcgetattr(STDOUT_FILENO, &d->tt) == 0 &&
-	 tcgetattr(STDIN_FILENO, &d->tt) == 0)
+
+   d->master = posix_openpt(O_RDWR | O_NOCTTY);
+   if (d->master == -1)
+      _error->Errno("posix_openpt", _("Can not write log (%s)"), _("Is /dev/pts mounted?"));
+   else if (unlockpt(d->master) == -1)
+      _error->Errno("unlockpt", "Unlocking the slave of master fd %d failed!", d->master);
+   else
    {
-      d->master = posix_openpt(O_RDWR | O_NOCTTY);
-      if (d->master == -1)
-	 _error->Errno("posix_openpt", _("Can not write log (%s)"), _("Is /dev/pts mounted?"));
-      else if (unlockpt(d->master) == -1)
-      {
-	 _error->Errno("unlockpt", "Unlocking the slave of master fd %d failed!", d->master);
-	 close(d->master);
-	 d->master = -1;
-      }
+      char const * const slave_name = ptsname(d->master);
+      if (slave_name == NULL)
+	 _error->Errno("ptsname", "Getting name for slave of master fd %d failed!", d->master);
       else
       {
-	 char const * const slave_name = ptsname(d->master);
-	 if (slave_name == NULL)
+	 d->slave = strdup(slave_name);
+	 if (d->slave == NULL)
+	    _error->Errno("strdup", "Copying name %s for slave of master fd %d failed!", slave_name, d->master);
+	 else if (grantpt(d->master) == -1)
+	    _error->Errno("grantpt", "Granting access to slave %s based on master fd %d failed!", slave_name, d->master);
+	 else if (tcgetattr(STDIN_FILENO, &d->tt) == 0)
 	 {
-	    _error->Errno("unlockpt", "Getting name for slave of master fd %d failed!", d->master);
-	    close(d->master);
-	    d->master = -1;
-	 }
-	 else
-	 {
-	    d->slave = strdup(slave_name);
-	    if (d->slave == NULL)
+	    d->tt_is_valid = true;
+	    struct termios raw_tt;
+	    // copy window size of stdout if its a 'good' terminal
+	    if (tcgetattr(STDOUT_FILENO, &raw_tt) == 0)
 	    {
-	       _error->Errno("strdup", "Copying name %s for slave of master fd %d failed!", slave_name, d->master);
-	       close(d->master);
-	       d->master = -1;
+	       struct winsize win;
+	       if (ioctl(STDOUT_FILENO, TIOCGWINSZ, &win) < 0)
+		  _error->Errno("ioctl", "Getting TIOCGWINSZ from stdout failed!");
+	       if (ioctl(d->master, TIOCSWINSZ, &win) < 0)
+		  _error->Errno("ioctl", "Setting TIOCSWINSZ for master fd %d failed!", d->master);
 	    }
-	    struct winsize win;
-	    if (ioctl(STDOUT_FILENO, TIOCGWINSZ, &win) < 0)
-	       _error->Errno("ioctl", "Getting TIOCGWINSZ from stdout failed!");
-	    if (ioctl(d->master, TIOCSWINSZ, &win) < 0)
-	       _error->Errno("ioctl", "Setting TIOCSWINSZ for master fd %d failed!", d->master);
 	    if (tcsetattr(d->master, TCSANOW, &d->tt) == -1)
 	       _error->Errno("tcsetattr", "Setting in Start via TCSANOW for master fd %d failed!", d->master);
 
-	    struct termios raw_tt;
 	    raw_tt = d->tt;
 	    cfmakeraw(&raw_tt);
 	    raw_tt.c_lflag &= ~ECHO;
@@ -1121,18 +1117,22 @@ void pkgDPkgPM::StartPtyMagic()
 	    sigaddset(&d->sigmask, SIGTTOU);
 	    sigprocmask(SIG_BLOCK,&d->sigmask, &d->original_sigmask);
 	    if (tcsetattr(STDIN_FILENO, TCSAFLUSH, &raw_tt) == -1)
-	       _error->Errno("tcsetattr", "Setting in Start via TCSAFLUSH for stdout failed!");
+	       _error->Errno("tcsetattr", "Setting in Start via TCSAFLUSH for stdin failed!");
 	    sigprocmask(SIG_SETMASK, &d->original_sigmask, NULL);
+
+	 }
+	 if (d->slave != NULL)
+	 {
+	    /* on linux, closing (and later reopening) all references to the slave
+	       makes the slave a death end, so we open it here to have one open all
+	       the time. We could use this fd in SetupSlavePtyMagic() for linux, but
+	       on kfreebsd we get an incorrect ("step like") output then while it has
+	       no problem with closing all references… so to avoid platform specific
+	       code here we combine both and be happy once more */
+	    d->protect_slave_from_dying = open(d->slave, O_RDWR | O_CLOEXEC);
 	 }
       }
    }
-   else
-   {
-      // complain only if stdout is either a terminal (but still failed) or is an invalid
-      // descriptor otherwise we would complain about redirection to e.g. /dev/null as well.
-      if (isatty(STDOUT_FILENO) == 1 || errno == EBADF)
-	 _error->Errno("tcgetattr", _("Can not write log (%s)"), _("Is stdout a terminal?"));
-   }
 
    if (_error->PendingError() == true)
    {
@@ -1141,17 +1141,23 @@ void pkgDPkgPM::StartPtyMagic()
 	 close(d->master);
 	 d->master = -1;
       }
+      if (d->slave != NULL)
+      {
+	 free(d->slave);
+	 d->slave = NULL;
+      }
       _error->DumpErrors(std::cerr);
    }
    _error->RevertToStack();
 }
 void pkgDPkgPM::SetupSlavePtyMagic()
 {
-   if(d->master == -1)
+   if(d->master == -1 || d->slave == NULL)
       return;
 
    if (close(d->master) == -1)
       _error->FatalE("close", "Closing master %d in child failed!", d->master);
+   d->master = -1;
    if (setsid() == -1)
       _error->FatalE("setsid", "Starting a new session for child failed!");
 
@@ -1166,7 +1172,7 @@ void pkgDPkgPM::SetupSlavePtyMagic()
 	 if (dup2(slaveFd, i) == -1)
 	    _error->FatalE("dup2", "Dupping %d to %d in child failed!", slaveFd, i);
 
-      if (tcsetattr(0, TCSANOW, &d->tt) < 0)
+      if (d->tt_is_valid == true && tcsetattr(STDIN_FILENO, TCSANOW, &d->tt) < 0)
 	 _error->FatalE("tcsetattr", "Setting in Setup via TCSANOW for slave fd %d failed!", slaveFd);
    }
 
@@ -1178,9 +1184,14 @@ void pkgDPkgPM::StopPtyMagic()
    if (d->slave != NULL)
       free(d->slave);
    d->slave = NULL;
+   if (d->protect_slave_from_dying != -1)
+   {
+      close(d->protect_slave_from_dying);
+      d->protect_slave_from_dying = -1;
+   }
    if(d->master >= 0) 
    {
-      if (tcsetattr(0, TCSAFLUSH, &d->tt) == -1)
+      if (d->tt_is_valid == true && tcsetattr(STDIN_FILENO, TCSAFLUSH, &d->tt) == -1)
 	 _error->FatalE("tcsetattr", "Setting in Stop via TCSAFLUSH for stdin failed!");
       close(d->master);
       d->master = -1;
diff --git a/test/integration/test-no-fds-leaked-to-maintainer-scripts b/test/integration/test-no-fds-leaked-to-maintainer-scripts
index 6ed1200..3c6457c 100755
--- a/test/integration/test-no-fds-leaked-to-maintainer-scripts
+++ b/test/integration/test-no-fds-leaked-to-maintainer-scripts
@@ -8,7 +8,7 @@ setupenvironment
 configarchitecture 'native'
 configdpkgnoopchroot
 
-setupsimplenativepackage "fdleaks" 'native' '1.0' 'unstable'
+setupsimplenativepackage "fdleaks" 'all' '1.0' 'unstable'
 BUILDDIR="incoming/fdleaks-1.0"
 for script in 'preinst' 'postinst' 'prerm' 'postrm'; do
 	echo '#!/bin/sh
@@ -19,7 +19,8 @@ rm -rf "$BUILDDIR"
 
 setupaptarchive
 
-testsuccess aptget install -y fdleaks
+rm -f rootdir/var/log/dpkg.log rootdir/var/log/apt/term.log
+testsuccess aptget install -y fdleaks -qq < /dev/null
 msgtest 'Check if fds were not' 'leaked'
 if [ "$(grep 'root root' rootdir/tmp/testsuccess.output | wc -l)" = '8' ]; then
 	msgpass
@@ -29,7 +30,23 @@ else
 	msgfail
 fi
 
-testsuccess aptget purge -y fdleaks
+cp rootdir/tmp/testsuccess.output terminal.output
+tail -n +3 rootdir/var/log/apt/term.log | head -n -1 > terminal.log
+testfileequal 'terminal.log' "$(cat terminal.output)"
+
+testequal 'startup archives unpack
+install fdleaks:all <none> 1.0
+status half-installed fdleaks:all 1.0
+status unpacked fdleaks:all 1.0
+status unpacked fdleaks:all 1.0
+startup packages configure
+configure fdleaks:all 1.0 <none>
+status unpacked fdleaks:all 1.0
+status half-configured fdleaks:all 1.0
+status installed fdleaks:all 1.0' cut -f 3- -d' ' rootdir/var/log/dpkg.log
+
+rm -f rootdir/var/log/dpkg.log rootdir/var/log/apt/term.log
+testsuccess aptget purge -y fdleaks -qq
 msgtest 'Check if fds were not' 'leaked'
 if [ "$(grep 'root root' rootdir/tmp/testsuccess.output | wc -l)" = '12' ]; then
 	msgpass
@@ -38,3 +55,20 @@ else
 	cat rootdir/tmp/testsuccess.output
 	msgfail
 fi
+cp rootdir/tmp/testsuccess.output terminal.output
+tail -n +3 rootdir/var/log/apt/term.log | head -n -1 > terminal.log
+testfileequal 'terminal.log' "$(cat terminal.output)"
+
+testequal 'startup packages purge
+status installed fdleaks:all 1.0
+remove fdleaks:all 1.0 <none>
+status half-configured fdleaks:all 1.0
+status half-installed fdleaks:all 1.0
+status config-files fdleaks:all 1.0
+purge fdleaks:all 1.0 <none>
+status config-files fdleaks:all 1.0
+status config-files fdleaks:all 1.0
+status config-files fdleaks:all 1.0
+status config-files fdleaks:all 1.0
+status config-files fdleaks:all 1.0
+status not-installed fdleaks:all <none>' cut -f 3- -d' ' rootdir/var/log/dpkg.log

Attachment: signature.asc
Description: Digital signature


Reply to: