(In reply to Bit Twister from comment #0)

> Steps to Reproduce:
> 
> see bug 10354 for install steps

Oops, that should  be

see bug 23530 for install steps

Created attachment 10355 [details]
report.bug.xz

Weird, this is the third recent bug report in which there are one or more messages about package install failing with "Too many levels of recursion in macro expansion" in stage2

If there was a packaging error, then we'd have such reports about package install or update in already installed systems, too, wouldn't we?

Also, it seems that those packages got installed, anyway. Can you check a few, to see whether they are installed?

CC: (none) => marja11, rpmstack
Source RPM: (none) => drakx-installer-stage2?
See Also: (none) => https://bugs.mageia.org/show_bug.cgi?id=23486, https://bugs.mageia.org/show_bug.cgi?id=23525
Assignee: bugsquad => mageiatools

(In reply to Marja Van Waes from comment #3)
> Weird, this is the third recent bug report in which there are one or more
> messages about package install failing with "Too many levels of recursion in
> macro expansion" in stage2

Yep, one of which is mine and supposedly it was traced down to info-install, sed. and/or shadow-utils, all of which I saw in the build system a day or so later.

> If there was a packaging error, then we'd have such reports about package
> install or update in already installed systems, too, wouldn't we?

Yeah, that was bothering me because on all my clean recursion problems, I boot my other cauldron install and do just updates without seeing any problems.

> Also, it seems that those packages got installed, anyway. Can you check a
> few, to see whether they are installed?

Yup, checked 15+ and all were installed. What I worry about is the possibility of other package(s) farther down the install dragging in those earlier packages.

That message have been bothering me before. For more info see Bug 12027
 - Too many levels of recursion in macro expansion - enhance message please

CC: (none) => fri

(In reply to Marja Van Waes from comment #3)

> 
> Also, it seems that those packages got installed, anyway. Can you check a
> few, to see whether they are installed?

Just now completed another clean network install with latest  drakx-installer-images and the orphan list is shorter than the previous install and based on a vague recollection of the previous orphans did indicate some of 91 really did fail install.

Pretty sure at this point there is an intermittent problem because this install had no recursion problems.

Are we using runtime expansion of macros in scriptlets?! As far as I knew, we're not doing that...

CC: (none) => ngompa13

I've just experienced the same problem with a new package I've just created. When it was installed by the installer, I got the message the package failed to install, due to too many levels of macro recursion. The package was installed, but the post-install script wasn't run. After installation, I uninstalled and reinstalled the package, and no errors were reported and the post-install script was run successfully. So I don't think this can be a packaging bug.

CC: (none) => mageia

What was the post script of that package?

CC: (none) => pterjan

(In reply to Pascal Terjan from comment #9)
> What was the post script of that package?

%post
if [ -d /boot/EFI/EFI ] ; then
    if [ ! -e /boot/EFI/EFI/refind ] ; then
        %{_sbindir}/refind-install --yes && cp %{_docdir}/%{name}/.README.installed %{_docdir}/%{name}/README.urpmi
    fi
fi

But the macros should be expanded at RPM build time, shouldn't they?

Yes they should, but I wondered which kind of macros would be broken.

There doesn't seem to be anything special in your post and a package built here with it has it correctly expanded at build time.

Can you check if this is the case on your package?

I believe rpm -qp --scripts foo.rpm should be enough but to be extra sure I also checked with strings foo.rpm | grep refind.

I'd already checked with rpm -qp --scripts, but couldn't be sure it wasn't hiding the problem... But strings gives me

   if [ ! -e /boot/EFI/EFI/refind ] ; then
        /usr/sbin/refind-install --yes && cp /usr/share/doc/refind/.README.installed /usr/share/doc/refind/README.urpmi

which settles the matter.

Well, running:


for pkg in *.rpm; do rpm -qp --scripts $pkg |grep \%;done

in distrib tree shows atleast some stuff that should be fixed / cleaned up...

Hm,
isn't there a rpmlint or youri check that should be able to detect /block stuff like this ...

CC: (none) => tmb

There's unexpanded-macro but it doesn't apply to scriptlets

But percent-in-%s does.
Eg: "percent-in-%preun"
So rejecting "percent-in-%" would do it.

CC: (none) => thierry.vignaud

(In reply to Bit Twister from comment #0)
> 5. grep 'levels of recursion' /root/drakx/ddebug.log
> 
> Copy of ddebug.log at 
>   https://bugs.mageia.org/attachment.cgi?id=10354&action=edit

About that message, this is printed by install::pkgs::_install_raw() which calls 
rpmlogMessage() (through URPM::rpmErrorString())

I suspect the message might be wrong here, like in C errno being set by the latest fscker.
What would be more relevant in such a case is /root/drakx/install.log or the full report.bug.

I suspect that install.log would show the real error...
ddebug.log is just not enough.

Summary: 91 rpms failed with Too many levels of recursion in macro expansion => 91 rpms failed with Too many levels of recursion in macro expansion (?)
Keywords: (none) => NEEDINFO

Sorry, installed wiped since new rpm, iso, stageX were released.
Providing a virtualbox guest all package groups and xfce DE only install with attachments.

Summary: 91 rpms failed with Too many levels of recursion in macro expansion (?) => 1278 rpms failed with Too many levels of recursion in macro expansion (?) xfce DE only install.
Keywords: NEEDINFO => (none)

Created attachment 10365 [details]
report.bug.xz

Created attachment 10366 [details]
install.log

Created attachment 10367 [details]
ddebug.log

/var/tmp/rpm-tmp.CeBkGm: line 1: /sbin/install-info: No such file or directory
%post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

Which causes a lot of failures to be reported for every pckages after that one, including in other transactions:

* lib64talloc2 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64tevent0 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64tdb1 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64ldb1 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64pytalloc-util2 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64pyglib2.0_0 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* python2-gobject not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* libnl3-config not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64nl3_200 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64nl-genl3_200 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64pcap1 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64pci3 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* perl-String-ShellQuote not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64parted2 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* python2-cairo not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64art_lgpl2 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127

* lib64magic1 not installed, %post(rcs-5.9.4-3.mga6.x86_64) scriptlet failed, exit status 127


[...]

It seems some error is not cleaned up

The code is:
                                my $check_installed = is_package_installed($db, $pkg);
[...]
                                if ($check_installed) {
                                    _unselect_package($packages, $pkg);
                                } else {
                                    log::l($pkg->name . " not installed, " . URPM::rpmErrorString());
                                }

So it seems they really don't get installed but the error message is not updated so we don't know why

Suprisingly install.log says they get installed:

starting installing packages
created transaction for installing on /mnt (remove=0, install=0, upgrade=50)
lib64talloc2-2.1.13-2.mga7.x86_64
[...]
removing installed rpms (ltrace-0.7.3-7.mga6.x86_64.rpm lib64ssh2_1-1.8.0-1.mga7.x86_64.rpm lib64blas3-3.8.0-3.mga7.x86_64.rpm lib64pcap1-1.9.0-1.mga7.x86_64.rpm lib64jansson4-2.11-1.mga7.x86_64.rpm lib64smbclient0-4.7.6-1.mga7.x86_64.rpm lib64kdc-samba4_2-4.7.6-1.mga7.x86_64.rpm perl-File-FnMatch-0.20.0-25.mga7.x86_64.rpm webserver-base-2.0-10.mga6.noarch.rpm python2-gobject-2.28.7-2.mga7.x86_64.rpm ghostscript-fonts-8.11-21.mga6.noarch.rpm libgfortran5-8.2.1-0.20180907.2.mga7.x86_64.rpm lib64talloc2-2.1.13-2.mga7.x86_64.rpm lib64ldb1-1.3.2-1.mga7.x86_64.rpm pygtk2.0-2.24.0-12.mga7.x86_64.rpm drakxtools-backend-17.98-2.mga7.x86_64.rpm libquadmath0-8.2.1-0.20180907.2.mga7.x86_64.rpm dia-0.97.3-7.mga6.x86_64.rpm samba-common-4.7.6-1.mga7.x86_64.rpm lib64magic1-5.33-2.mga7.x86_64.rpm lib64art_lgpl2-2.3.21-10.mga7.x86_64.rpm lib64samba1-4.7.6-1.mga7.x86_64.rpm python2-cairo-1.15.3-3.mga7.x86_64.rpm python2-numpy-1.15.0-1.mga7.x86_64.rpm gzip-1.9-3.mga7.x86_64.rpm bootloader-utils-1.16-6.mga6.noarch.rpm lib64tdb1-1.3.15-1.mga7.x86_64.rpm rootfiles-11.0-14.mga6.noarch.rpm nmap-7.70-1.mga7.x86_64.rpm lib64nl-genl3_200-3.4.0-2.mga7.x86_64.rpm lib64wbclient0-4.7.6-1.mga7.x86_64.rpm lib64nl3_200-3.4.0-2.mga7.x86_64.rpm ldetect-lst-0.4.9-2.mga7.x86_64.rpm lib64parted2-3.2-8.mga7.x86_64.rpm perl-String-ShellQuote-1.40.0-11.mga7.noarch.rpm lib64lapack3-3.8.0-3.mga7.x86_64.rpm lib64samba-dc0-4.7.6-1.mga7.x86_64.rpm file-5.33-2.mga7.x86_64.rpm lib64ldetect0.12-0.12.8-3.mga6.x86_64.rpm lib64pytalloc-util2-2.1.13-2.mga7.x86_64.rpm ldetect-0.12.8-3.mga6.x86_64.rpm lib64tevent0-0.9.37-1.mga7.x86_64.rpm etcskel-1.63-34.mga6.noarch.rpm lib64pci3-3.5.5-1.mga7.x86_64.rpm crontabs-1.10-22.mga6.noarch.rpm less-533-1.mga7.x86_64.rpm libnl3-config-3.4.0-2.mga7.noarch.rpm lib64pyglib2.0_0-2.28.7-2.mga7.x86_64.rpm samba-client-4.7.6-1.mga7.x86_64.rpm lib64telepathy-farstream3-0.6.2-9.mga6.x86_64.rpm) from /mnt/var/cache/urpmi/rpms

So it would be is_package_installed which is broken?

Another leaked message earlier in the log:

* netprofile-plugin-urpmi not installed, /etc/rpm/macros created as /etc/rpm/macros.rpmnew

* netprofile-plugin-services not installed, /etc/rpm/macros created as /etc/rpm/macros.rpmnew

* netprofile-plugin-proxy not installed, /etc/rpm/macros created as /etc/rpm/macros.rpmnew

* netprofile-plugin-network not installed, /etc/rpm/macros created as /etc/rpm/macros.rpmnew

* netprofile-plugin-firewall not installed, /etc/rpm/macros created as /etc/rpm/macros.rpmnew

It is starting from the first transaction, all packages are reported "not installed" with an unrelated message:

* popt-data not installed, Generating 18 missing index(es), please wait...

* dash-static not installed, Generating 18 missing index(es), please wait...

* pkgconf-m4 not installed, Generating 18 missing index(es), please wait...

* timezone-java not installed, Generating 18 missing index(es), please wait...

My suspicion is on is_package_installed being broken but there is no obvious way to know how (not finding the package by name or comparison failing on one of the E/V/R/A)

Created attachment 10369 [details]
debugging patch example

You can unsquashfs the stage2 into eg /x86_64/install/stage2/live and then add whatever debugging you want to be used with drakx-in-chroot.

Here it looks like the pkg is not found when traversing the db

I wonder if there wasn't a recent rpm regression...

(In reply to Thierry Vignaud from comment #27)
> I wonder if there wasn't a recent rpm regression...

In my case (testing bootloader package installation), 'rpm -qa' showed the package had been installed, but the post install script was not run. But if I go to the console in the installer, chroot into the installed system, and install the package using urpmi, it installs correctly, including running the post install script.

There are several problems:
- some packages having post failing (like the missing install-info for rcs, I would move it to postrans with proper dependency)
- everything being considered as failed despite having no error, and logging the most recent warning/error message each time
- the specific error about macro expansion which in the given log is first logged for the update of chrony (and then for other services and bootloader stuff) but there is no error logged for %pre or %post of chrony and installation succeeds so I guess it is again a leftover of something else, probably not of the installation of a package

I may have missed some but the only 2 places I found with interesting macro usage are:

    URPM::add_macro(join(' ', '__dbi_cdb', URPM::expand('%__dbi_cdb'), 'nofsync'));
    URPM::add_macro(URPM::expand('__dbi_cdb %__dbi_cdb nofsync'));

Given that __dbi_cdb seems undefined, I expect __dbi_cdb to bet set to "%__dbi_cdb nofsync" which would explain the error message the next time URPM::expand is called.

$ rpm --showrc | grep __dbi
-13: __dbi_other	mp_mmapsize=128Mb mp_size=1Mb
-13: _dbi_config	%{?__dbi_other}

So the real problem would still really be is_package_installed and not this message which just leak into the package install.

We need to alter  __dbi_other as  __dbi_cdb got killed in 2010.
I think we might just stop calling rpmErrorString() (install.log will have the details anyway)
About is_package_installed(), I've tried reopening rpm DB there but that show the same result.

(In reply to Bit Twister from comment #19)
> Created attachment 10367 [details]
> ddebug.log

You don't need to attach ddebug.log & install.log, those are already in report.bug.xz

(In reply to Thierry Vignaud from comment #27)
> I wonder if there wasn't a recent rpm regression...

I'm wondering if this commit doesn't cause one extra open/close callback calls in drakx:
https://github.com/rpm-software-management/rpm/commit/5064276cd946183d711430da44b18608af74ebf1

Yep it looks like this the winner.
Adding support for verify in URPM so that we could do some things in urpmi & drakx

I've commits in URPM, urpmi & in drakx and voila, no more issue...

Fixed in git

Status: NEW => RESOLVED
Resolution: (none) => FIXED

*** Bug 23486 has been marked as a duplicate of this bug. ***