[dm-devel] [PATCH] kpartx: print "loop deleted" to stdout, not stderr

[Martin Wilck]

On Mon, 2018-02-05 at 15:17 +0100, Julian Andres Klode wrote:
> On Mon, Feb 05, 2018 at 03:12:33PM +0100, Julian Andres Klode wrote:
> > On Mon, Feb 05, 2018 at 02:58:46PM +0100, Martin Wilck wrote:
> > > On Mon, 2018-02-05 at 11:36 +0100, Julian Andres Klode wrote:
> > > > Commit fa643f5d2590028a59c671b81ab41383806fd258 moved some
> > > > code around and changed the print for loop deleted from stdout
> > > > to stderr - but this is not an error message, and also printed
> > > > to stdout in another place, so let's just use printf() again
> > > > here.
> > > > 
> > > > Signed-off-by: Julian Andres Klode <julian.klode at canonical.com>
> > > > ---
> > > >  kpartx/kpartx.c | 2 +-
> > > >  1 file changed, 1 insertion(+), 1 deletion(-)
> > > > 
> > > > diff --git a/kpartx/kpartx.c b/kpartx/kpartx.c
> > > > index c1af1c5e..2e882721 100644
> > > > --- a/kpartx/kpartx.c
> > > > +++ b/kpartx/kpartx.c
> > > > @@ -399,7 +399,7 @@ main(int argc, char **argv){
> > > >  					       loopdev);
> > > >  				r = 1;
> > > >  			} else
> > > > -				fprintf(stderr, "loop deleted
> > > > :
> > > > %s\n", loopdev);
> > > > +				printf("loop deleted : %s\n",
> > > > loopdev);
> > > >  		}
> > > >  		goto end;
> > > >  	}
> > > 
> > > 
> > > Hm. This is a log message, and as such, should go to stderr.
> > > kpartx, as
> > > a program primarily intended to run in udev rules, shouldn't
> > > print log
> > > messages to stdout unless we have compelling reasons for it to do
> > > so.
> > > 
> > > I'm aware that this isn't done consistently in kpartx at the
> > > moment,
> > > but IMO your patch goes in the wrong direction.
> > 
> > It seems very consistent for me: stderr is used for errors and
> > warnings,
> > and printf() for the rest. There are two exceptions: This one, and
> > 
> > kpartx/devmapper.c:             fprintf(stderr, "found map %s for
> > uuid %s, renaming to %s\n",
> > 
> > But that one really is what I'd consider a log message. Stuff like
> > "del devmap" and "loop deleted" seem somehow different - you tell
> > it to delete a mapping, and to be verbose, and then it should tell
> > you what it deleted, on stdout. Maybe people are parsing this, who
> > knows? It definitely broke our tests because unexpected stderr
> > output
> > appeared.
> > 
> 
> In fact, if you look at the bug mentioned in the previous patch,
> 
> https://bugs.launchpad.net/ubuntu/+source/multipath-tools/+bug/174704
> 4
> 
> you'll see that we explicitly check the output of kpartx -v -d for
> "loop deleted" apparently because kpartx was (or is?) flaky and
> returned
> an error even when it successfully deleted the loop device, as seen
> in
> 
> https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=860894

That's a very different issue. Without digging much deeper into it, I'd
like to repeat that kpartx' job is to delete _partition mappings_, not
loop devices. The ability to delete the loop device as well ist just a
convenience, saving users another call to "losetup -d". So it's not
necessarily "flaky" for kpartx to return a non-zero error code if
errors were encountered during it's core task (removing the
partitions), even if removing the loop device was successful later. (*)
> 
> It seems reasonable that Debian and Ubuntu are not the only ones
> relying on that output.

The fact that they rely on parsing this this message on stdout is
sufficient justification for me to keep it there, even though I'm not
buying your "errors to stderr, the rest to stdout" argument in general.

Please submit again, adding a comment that Ubuntu/Debian rely on the
presence of this output, lest it be changed again in the future.

Regards
Martin

(*) One might argue whether the loop device shouldn't have been deleted
in that error case, but that's yet another issue.

-- 
Dr. Martin Wilck <mwilck at suse.com>, Tel. +49 (0)911 74053 2107
SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton
HRB 21284 (AG Nürnberg)