"Use of uninitialized value" in debconf via update-manager

[Francesco Abeni]

During a software upgrade, process was stuck on php7.0-xml configuration for 20 minutes, after that I killed the process. I am not sure what additional info are required, will be happy to provide any.

ProblemType: Package
DistroRelease: Ubuntu 16.04
Package: php7.0-xml 7.0.13-0ubuntu0.16.04.1
ProcVersionSignature: Ubuntu 4.4.0-49.70-generic 4.4.30
Uname: Linux 4.4.0-49-generic x86_64
ApportVersion: 2.20.1-0ubuntu2.2
Architecture: amd64
Date: Fri Dec 2 09:52:06 2016
ErrorMessage: subprocess installed post-installation script returned error exit status 128
InstallationDate: Installed on 2016-03-11 (265 days ago)
InstallationMedia: Ubuntu-GNOME 15.10 "Wily Werewolf" - Release amd64 (20151021)
RelatedPackageVersions:
 dpkg 1.18.4ubuntu1.1
 apt 1.2.15
SourcePackage: php7.0
Title: package php7.0-xml 7.0.13-0ubuntu0.16.04.1 failed to install/upgrade: subprocess installed post-installation script returned error exit status 128
UpgradeStatus: Upgraded to xenial on 2016-05-07 (209 days ago)

[Nish Aravamudan (nacc)]

Hello and thank you for testing the update in -proposed!

From DpgkTerminalLog.txt:

Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 14.
Use of uninitialized value $val in substitution (s///) at /usr/share/perl5/Debconf/Format/822.pm line 83, <GEN1> line 10.
Use of uninitialized value $val in concatenation (.) or string at /usr/share/perl5/Debconf/Format/822.pm line 84, <GEN1> line 10.
Setting up php7.0-xml (7.0.13-0ubuntu0.16.04.1) ...
Use of uninitialized value $reply in scalar chomp at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 66.
Use of uninitialized value $reply in concatenation (.) or string at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 67.
Use of uninitialized value $reply in split at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 68.
Use of uninitialized value $reply in scalar chomp at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 66.
Use of uninitialized value $reply in concatenation (.) or string at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 67.
Use of uninitialized value $reply in split at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 68.
Use of uninitialized value $reply in scalar chomp at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 66.
Use of uninitialized value $reply in concatenation (.) or string at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 67.
Use of uninitialized value $reply in split at /usr/share/perl5/Debconf/FrontEnd/Passthrough.pm line 68.
dpkg: error processing package php7.0-xml (--configure):
 subprocess installed post-installation script returned error exit status 128

Unfortunately, we have seen this before (not necessarily only with php7.0), and it's unclear why debconf is failing. I do not believe this is an actual issue in php7.0's update (and I can't reproduce this locally).

In the paste, we've wondered if perhaps a debconf prompt race is occurring (or perhaps was skipped/ignored?). You mentioned that 'process was stuck on php7.0-xml configuration '. Could you specify what exactly was emitted on your screen that seemed stuck? Do you have any local php7.0-xml configuration modifications?

Thanks again,
Nish

[Francesco Abeni (f-abeni)]

The system was performing an "apt upgrade" via Gnome Software Update. As usual, after the download part, a new line appears for each package while that package is actually installed and configured. E.g.

   Configuring php7.0-mysql
   Configuring php7.0-json
   Configuring php7.0-mbstring

and so on. When it came to "Configuring php7.0-xml", no further progress appeared, the CPU usage was quite high. After about 20 minutes I killed the process.

No, I don't have any local package modification.

Thank you for taking care of this.

[Nish Aravamudan (nacc)]

@Francisco, are you able to install the packages successfully from the command-line? I'm worried there is some prompting occurring that is being ignored (raced?) with the GUI and that is what is causing the traceback.

[Francesco Abeni (f-abeni)]

Yes I was able to update everything via command line.

This error happened only once; all the other times I ran an upgrade (either via GUI or via command line) everything went fine.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Francesco Abeni (f-abeni)]

This has just happened again. I was doing normal updates via GUI as requested by the operating system and it got stuck once again ath php7.0-xml configuration.

Found a process "php7.0-xml.postinst", killed it, update was able to continue.

Launched "apt upgrade" from command line and everything went fine (package configuration was done in seconds).

[Nish Aravamudan (nacc)]

Thank you for the reponse! Which GUI program did you use? I am thinking now, given that apt succeeded, that it is a bug in the GUI program itself, although I'm not sure where. I also will try to setup a VM today that has PHP and a GUI installed (I've only ever used it on headless servers and in test containers/VMs over ssh).

[Francesco Abeni (f-abeni)]

It's update-manager on Ubuntu Gnome 16.04.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Nish Aravamudan (nacc)]

For those who filed bugs I just duped here, there seems to be an underlying issue with update-manager invoking aptdaemon which in turn seems to think it needs to call a maintscript (although it doesn't necessarily) which then errors out.

Using cli tools instead, this does not occur.

This is not specific to php7.0 at all, but is something seen across many packages always involving update-manager.

I have seen at least a few historic bugs (supposedly fixed) and am still doing archaeology to see if something maybe was dropped: LP: #804250, LP: #779970, LP: #845367.

[Nish Aravamudan (nacc)]

For those that do see this issue, is it reproducible from update-manager? That is, once it happens, if you cancle/quit update-manager, and then try to use it to update again, does it again hang (e.g., on php7.0-xml as in this bug report).

If so, we might be able to get some more debugging by modifying the postinst locally.

@f-abeni: do you have any local modifications to your php-xml .ini file snippet? Also, if you do re-encounter the hang, does /var/log/apt/history.log contain the "Use of uninitialized value" errors already (before you hit cancel or kill update-manager)?

[Francesco Abeni (f-abeni)]

@nacc:

* yes it hangs again if I just quit and restart
* no I don't have any local modifications in the .ini file
* I will follow your instructions next time I encounter the bug.

[Nish Aravamudan (nacc)]

@f-abeni: while it might not seem like it, that's actually good!

So, yes, if you can provide the history.log and possibly, alter the postinst that hangs locally to use `set +x`, re-run update-manager and see if history.log has the output from that postinst and we can hopefully figure out what exactly is hanging.

[Nish Aravamudan (nacc)]

@es20490446e: how can you have a Critical Invalid bug?

Also, "Critical" is listed as "Fix now or as soon as possible". Except we don't have a reproducible test case and there is a fairly easy workaround (and probably most server users are actually unaffected by this as they are GUI-free). This bug has been present in one form or another since Oneiric (at least), periodically showing up. As of right now, I have no fix planned (nor do I know of anyone that does) and I don't think it should block the release.

[Christian Ehrhardt  (paelzer)]

FYI as nacc asked, I added samba task to reflect that it showed up there as well (I dupped another case onto this).

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Nish Aravamudan (nacc)]

@Alberto,

why did you mark the samba task critical? As far as I can tell, there is no bug in samba itself, all of these bugs are in update-manager and just have been seen with various binary packages which we're marking this bug and then indicating they are invalid.

[Mikkel Kirkgaard Nielsen (mikini)]

This happened to me yesterday on a 16.04 desktop system using update-manager. Apparently failed during setup of package unattended-upgrades.

Below is apt/history.log, apt/term.log, ps and debconf version taken while the GUI has been hanging (greyed out and unresponsive) for ~15 hours. GUI screenshot as shown in attachment.

$ tail -4 /var/log/apt/history.log
Start-Date: 2017-05-20 21:12:22
Commandline: aptdaemon role='role-commit-packages' sender=':1.438'
Upgrade: iproute:amd64 (1:4.3.0-1ubuntu3, 1:4.3.0-1ubuntu3.16.04.1), iproute2:amd64 (4.3.0-1ubuntu3, 4.3.0-1ubuntu3.16.04.1), unattended-upgrades:amd64 (0.90ubuntu0.5, 0.90ubuntu0.6), libjasper1:amd64 (1.900.1-debian1-2.4ubuntu1, 1.900.1-debian1-2.4ubuntu1.1)
End-Date: 2017-05-20 21:12:29

$ tail -23 /var/log/apt/term.log
Log started: 2017-05-20 21:12:22
(Reading database ... 359114 files and directories currently installed.)
Preparing to unpack .../iproute2_4.3.0-1ubuntu3.16.04.1_amd64.deb ...
Unpacking iproute2 (4.3.0-1ubuntu3.16.04.1) over (4.3.0-1ubuntu3) ...
Preparing to unpack .../iproute_1%3a4.3.0-1ubuntu3.16.04.1_all.deb ...
Unpacking iproute (1:4.3.0-1ubuntu3.16.04.1) over (1:4.3.0-1ubuntu3) ...
Preparing to unpack .../libjasper1_1.900.1-debian1-2.4ubuntu1.1_amd64.deb ...
Unpacking libjasper1:amd64 (1.900.1-debian1-2.4ubuntu1.1) over (1.900.1-debian1-2.4ubuntu1) ...
Preparing to unpack .../unattended-upgrades_0.90ubuntu0.6_all.deb ...
Unpacking unattended-upgrades (0.90ubuntu0.6) over (0.90ubuntu0.5) ...
Processing triggers for man-db (2.7.5-1) ...
Processing triggers for libc-bin (2.23-0ubuntu7) ...
Processing triggers for systemd (229-4ubuntu17) ...
Processing triggers for ureadahead (0.100.0-19) ...
Setting up iproute2 (4.3.0-1ubuntu3.16.04.1) ...
Setting up iproute (1:4.3.0-1ubuntu3.16.04.1) ...
Setting up libjasper1:amd64 (1.900.1-debian1-2.4ubuntu1.1) ...
Setting up unattended-upgrades (0.90ubuntu0.6) ...
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 12.
Use of uninitialized value $val in substitution (s///) at /usr/share/perl5/Debconf/Format/822.pm line 83, <GEN7> line 11.
Use of uninitialized value $val in concatenation (.) or string at /usr/share/perl5/Debconf/Format/822.pm line 84, <GEN7> line 11.
Processing triggers for libc-bin (2.23-0ubuntu7) ...
Log ended: 2017-05-20 21:12:29

$ ps aux |grep update
miki 5027 0.0 1.2 730908 95960 ? Sl May20 0:20 /usr/bin/python3 /usr/bin/update-manager
miki 10100 0.0 0.2 591036 22164 ? Sl May20 0:01 update-notifier

$ dpkg -l|grep debconf |head -1
ii debconf 1.5.58ubuntu1 all Debian configuration management system

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 16.04.2 LTS
Release: 16.04
Codename: xenial

[Brian Murray (brian-murray)]

Actually, I'm not convinced that update-manager is the front end in use here. If we look at the JournalErrors.txt file attached to this bug we can see the following:

dic 02 09:33:40 hostname org.debian.apt[871]: 09:33:40 AptDaemon [INFO]: Initializing daemon
dic 02 09:33:40 hostname org.debian.apt[871]: /usr/lib/python3/dist-packages/aptdaemon/worker/pkworker.py:35: PyGIWarning: PackageKitGlib was imported without specifying a version first. Use gi.require_version('PackageKitGlib', '1.0') before import to ensure that the right version gets loaded.
dic 02 09:33:40 hostname org.debian.apt[871]: from gi.repository import PackageKitGlib as pk

My testing indicates that these errors only appear in the journal when gnome-software is being used and not update-manager.

[Steve Langasek (vorlon)]

If this is gnome-software, then this should be fixed already in gnome-software 3.20.1+git20170427.0.3d09239-0ubuntu1~xenial1

[Paul Wellner Bou (paul-natyyjkkrqk00yyc0o)]

I just ran into the same problem:

```
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88299.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88306.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88315.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88322.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88331.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88338.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88347.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88354.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88363.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88370.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88379.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88386.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88395.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88402.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88411.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88418.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88427.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88434.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88443.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88450.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88459.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88466.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88475.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88482.
Use of uninitialized value $_[1] in join or string at /usr/share/perl5/Debconf/DbDriver/Stack.pm line 111, <GEN0> line 88491.
Use of unin...