[PATCH] rpm: produce sane amount of logging when creating a rootfs

[PATCH] rpm: produce sane amount of logging when creating a rootfs

[Alexander Kanavin]

Previously there was lots of irrelevant noise in the logs,
because we also wanted to be able to debug postinst issues
easily. I have adjusted the logging levels so that
postinst info is still written to the logs, but other
things are not.

[YOCTO #13119]

Signed-off-by: Alexander Kanavin <alex.kanavin@gmail.com>
---
 meta/lib/oe/package_manager.py                |  2 +-
 ...ge-logging-level-around-scriptlets-t.patch | 55 +++++++++++++++++++
 meta/recipes-devtools/rpm/rpm_4.14.2.1.bb     |  1 +
 3 files changed, 57 insertions(+), 1 deletion(-)
 create mode 100644 meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch

diff --git a/meta/lib/oe/package_manager.py b/meta/lib/oe/package_manager.py
index 392fe7e3724..7ff76c61cdd 100644
--- a/meta/lib/oe/package_manager.py
+++ b/meta/lib/oe/package_manager.py
@@ -966,7 +966,7 @@ class RpmPM(PackageManager):
         os.environ['RPM_ETCCONFIGDIR'] = self.target_rootfs
 
         dnf_cmd = bb.utils.which(os.getenv('PATH'), "dnf")
-        standard_dnf_args = ["-v", "--rpmverbosity=debug", "-y",
+        standard_dnf_args = ["-v", "--rpmverbosity=info", "-y",
                              "-c", oe.path.join(self.target_rootfs, "etc/dnf/dnf.conf"),
                              "--setopt=reposdir=%s" %(oe.path.join(self.target_rootfs, "etc/yum.repos.d")),
                              "--installroot=%s" % (self.target_rootfs),
diff --git a/meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch b/meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch
new file mode 100644
index 00000000000..43e9859ef32
--- /dev/null
+++ b/meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch
@@ -0,0 +1,55 @@
+From 989e425d416474c191b020d0825895e3df4bd033 Mon Sep 17 00:00:00 2001
+From: Alexander Kanavin <alex.kanavin@gmail.com>
+Date: Thu, 10 Jan 2019 18:14:18 +0100
+Subject: [PATCH] rpmscript.c: change logging level around scriptlets to INFO
+ from DEBUG
+
+That way we can debug scriptlet failures without writing lots of
+irrelevant noise to rootfs logs.
+
+Upstream-Status: Inappropriate [oe-core specific]
+Signed-off-by: Alexander Kanavin <alex.kanavin@gmail.com>
+---
+ lib/rpmscript.c | 8 ++++----
+ 1 file changed, 4 insertions(+), 4 deletions(-)
+
+diff --git a/lib/rpmscript.c b/lib/rpmscript.c
+index 2b0e43862..e319673f1 100644
+--- a/lib/rpmscript.c
++++ b/lib/rpmscript.c
+@@ -226,7 +226,7 @@ static char * writeScript(const char *cmd, const char *script)
+     if (Ferror(fd))
+ 	goto exit;
+ 
+-    if (rpmIsDebug() && (rstreq(cmd, "/bin/sh") || rstreq(cmd, "/bin/bash"))) {
++    if (rpmIsVerbose() && (rstreq(cmd, "/bin/sh") || rstreq(cmd, "/bin/bash"))) {
+ 	static const char set_x[] = "set -x\n";
+ 	/* Assume failures will be caught by the write below */
+ 	Fwrite(set_x, sizeof(set_x[0]), sizeof(set_x)-1, fd);
+@@ -258,7 +258,7 @@ static rpmRC runExtScript(rpmPlugins plugins, ARGV_const_t prefixes,
+     char *mline = NULL;
+     rpmRC rc = RPMRC_FAIL;
+ 
+-    rpmlog(RPMLOG_DEBUG, "%s: scriptlet start\n", sname);
++    rpmlog(RPMLOG_INFO, "%s: scriptlet start\n", sname);
+ 
+     if (script) {
+ 	fn = writeScript(*argvp[0], script);
+@@ -310,7 +310,7 @@ static rpmRC runExtScript(rpmPlugins plugins, ARGV_const_t prefixes,
+ 		sname, strerror(errno));
+ 	goto exit;
+     } else if (pid == 0) {/* Child */
+-	rpmlog(RPMLOG_DEBUG, "%s: execv(%s) pid %d\n",
++	rpmlog(RPMLOG_INFO, "%s: execv(%s) pid %d\n",
+ 	       sname, *argvp[0], (unsigned)getpid());
+ 
+ 	fclose(in);
+@@ -353,7 +353,7 @@ static rpmRC runExtScript(rpmPlugins plugins, ARGV_const_t prefixes,
+ 	reaped = waitpid(pid, &status, 0);
+     } while (reaped == -1 && errno == EINTR);
+ 
+-    rpmlog(RPMLOG_DEBUG, "%s: waitpid(%d) rc %d status %x\n",
++    rpmlog(RPMLOG_INFO, "%s: waitpid(%d) rc %d status %x\n",
+ 	   sname, (unsigned)pid, (unsigned)reaped, status);
+ 
+     if (reaped < 0) {
diff --git a/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb b/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb
index ef5d631917c..66eef557dfa 100644
--- a/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb
+++ b/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb
@@ -40,6 +40,7 @@ SRC_URI = "git://github.com/rpm-software-management/rpm;branch=rpm-4.14.x \
            file://0004-build-pack.c-remove-static-local-variables-from-buil.patch \
            file://0001-perl-disable-auto-reqs.patch \
            file://0001-rpm-rpmio.c-restrict-virtual-memory-usage-if-limit-s.patch \
+           file://0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch \
            "
 
 PE = "1"
-- 
2.17.1

Re: [PATCH] rpm: produce sane amount of logging when creating a rootfs

[Mark Hatle]

I'm slightly worried that this will break on-target RPM users.  Since info is
commonly enabled during on-target installations to track which packages have
been installed and what their progress is.

Has it been test that this does not break dnf on the target?

--Mark

On 1/11/19 4:43 AM, Alexander Kanavin wrote:
> Previously there was lots of irrelevant noise in the logs,
> because we also wanted to be able to debug postinst issues
> easily. I have adjusted the logging levels so that
> postinst info is still written to the logs, but other
> things are not.
> 
> [YOCTO #13119]
> 
> Signed-off-by: Alexander Kanavin <alex.kanavin@gmail.com>
> ---
>  meta/lib/oe/package_manager.py                |  2 +-
>  ...ge-logging-level-around-scriptlets-t.patch | 55 +++++++++++++++++++
>  meta/recipes-devtools/rpm/rpm_4.14.2.1.bb     |  1 +
>  3 files changed, 57 insertions(+), 1 deletion(-)
>  create mode 100644 meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch
> 
> diff --git a/meta/lib/oe/package_manager.py b/meta/lib/oe/package_manager.py
> index 392fe7e3724..7ff76c61cdd 100644
> --- a/meta/lib/oe/package_manager.py
> +++ b/meta/lib/oe/package_manager.py
> @@ -966,7 +966,7 @@ class RpmPM(PackageManager):
>          os.environ['RPM_ETCCONFIGDIR'] = self.target_rootfs
>  
>          dnf_cmd = bb.utils.which(os.getenv('PATH'), "dnf")
> -        standard_dnf_args = ["-v", "--rpmverbosity=debug", "-y",
> +        standard_dnf_args = ["-v", "--rpmverbosity=info", "-y",
>                               "-c", oe.path.join(self.target_rootfs, "etc/dnf/dnf.conf"),
>                               "--setopt=reposdir=%s" %(oe.path.join(self.target_rootfs, "etc/yum.repos.d")),
>                               "--installroot=%s" % (self.target_rootfs),
> diff --git a/meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch b/meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch
> new file mode 100644
> index 00000000000..43e9859ef32
> --- /dev/null
> +++ b/meta/recipes-devtools/rpm/files/0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch
> @@ -0,0 +1,55 @@
> +From 989e425d416474c191b020d0825895e3df4bd033 Mon Sep 17 00:00:00 2001
> +From: Alexander Kanavin <alex.kanavin@gmail.com>
> +Date: Thu, 10 Jan 2019 18:14:18 +0100
> +Subject: [PATCH] rpmscript.c: change logging level around scriptlets to INFO
> + from DEBUG
> +
> +That way we can debug scriptlet failures without writing lots of
> +irrelevant noise to rootfs logs.
> +
> +Upstream-Status: Inappropriate [oe-core specific]
> +Signed-off-by: Alexander Kanavin <alex.kanavin@gmail.com>
> +---
> + lib/rpmscript.c | 8 ++++----
> + 1 file changed, 4 insertions(+), 4 deletions(-)
> +
> +diff --git a/lib/rpmscript.c b/lib/rpmscript.c
> +index 2b0e43862..e319673f1 100644
> +--- a/lib/rpmscript.c
> ++++ b/lib/rpmscript.c
> +@@ -226,7 +226,7 @@ static char * writeScript(const char *cmd, const char *script)
> +     if (Ferror(fd))
> + 	goto exit;
> + 
> +-    if (rpmIsDebug() && (rstreq(cmd, "/bin/sh") || rstreq(cmd, "/bin/bash"))) {
> ++    if (rpmIsVerbose() && (rstreq(cmd, "/bin/sh") || rstreq(cmd, "/bin/bash"))) {
> + 	static const char set_x[] = "set -x\n";
> + 	/* Assume failures will be caught by the write below */
> + 	Fwrite(set_x, sizeof(set_x[0]), sizeof(set_x)-1, fd);
> +@@ -258,7 +258,7 @@ static rpmRC runExtScript(rpmPlugins plugins, ARGV_const_t prefixes,
> +     char *mline = NULL;
> +     rpmRC rc = RPMRC_FAIL;
> + 
> +-    rpmlog(RPMLOG_DEBUG, "%s: scriptlet start\n", sname);
> ++    rpmlog(RPMLOG_INFO, "%s: scriptlet start\n", sname);
> + 
> +     if (script) {
> + 	fn = writeScript(*argvp[0], script);
> +@@ -310,7 +310,7 @@ static rpmRC runExtScript(rpmPlugins plugins, ARGV_const_t prefixes,
> + 		sname, strerror(errno));
> + 	goto exit;
> +     } else if (pid == 0) {/* Child */
> +-	rpmlog(RPMLOG_DEBUG, "%s: execv(%s) pid %d\n",
> ++	rpmlog(RPMLOG_INFO, "%s: execv(%s) pid %d\n",
> + 	       sname, *argvp[0], (unsigned)getpid());
> + 
> + 	fclose(in);
> +@@ -353,7 +353,7 @@ static rpmRC runExtScript(rpmPlugins plugins, ARGV_const_t prefixes,
> + 	reaped = waitpid(pid, &status, 0);
> +     } while (reaped == -1 && errno == EINTR);
> + 
> +-    rpmlog(RPMLOG_DEBUG, "%s: waitpid(%d) rc %d status %x\n",
> ++    rpmlog(RPMLOG_INFO, "%s: waitpid(%d) rc %d status %x\n",
> + 	   sname, (unsigned)pid, (unsigned)reaped, status);
> + 
> +     if (reaped < 0) {
> diff --git a/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb b/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb
> index ef5d631917c..66eef557dfa 100644
> --- a/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb
> +++ b/meta/recipes-devtools/rpm/rpm_4.14.2.1.bb
> @@ -40,6 +40,7 @@ SRC_URI = "git://github.com/rpm-software-management/rpm;branch=rpm-4.14.x \
>             file://0004-build-pack.c-remove-static-local-variables-from-buil.patch \
>             file://0001-perl-disable-auto-reqs.patch \
>             file://0001-rpm-rpmio.c-restrict-virtual-memory-usage-if-limit-s.patch \
> +           file://0016-rpmscript.c-change-logging-level-around-scriptlets-t.patch \
>             "
>  
>  PE = "1"
> 

Re: [PATCH] rpm: produce sane amount of logging when creating a rootfs

[Burton, Ross]

[-- Attachment #1: Type: text/plain, Size: 518 bytes --]

On Fri, 11 Jan 2019 at 15:50, Mark Hatle <mark.hatle@windriver.com> wrote:

> I'm slightly worried that this will break on-target RPM users.  Since info
> is
> commonly enabled during on-target installations to track which packages
> have
> been installed and what their progress is.
>
> Has it been test that this does not break dnf on the target?


Easy fix: make this specific to class-native.

That's probably sensible even if it doesn't break dnf, because then target
RPM behaves as usual.

Ross

[-- Attachment #2: Type: text/html, Size: 896 bytes --]

Re: [PATCH] rpm: produce sane amount of logging when creating a rootfs

[Alexander Kanavin]

On Fri, 11 Jan 2019 at 16:53, Burton, Ross <ross.burton@intel.com> wrote:
>> I'm slightly worried that this will break on-target RPM users.  Since info is
>> commonly enabled during on-target installations to track which packages have
>> been installed and what their progress is.
>>
>> Has it been test that this does not break dnf on the target?
>
>
> Easy fix: make this specific to class-native.
>
> That's probably sensible even if it doesn't break dnf, because then target RPM behaves as usual.

I'm not too worried as dnf interacts with rpm via rpm's python API;
what rpm prints out should be of no consequence.
The extra lines are probably useful for the target as well, since
postinsts can fail in various ways there too.
If this passes the dnf/rpm tests on the AB, I'd leave it like it is.

Alex