Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Received-SPF: Pass (protection.outlook.com: domain of sony.com designates
 160.33.194.231 as permitted sender) receiver=protection.outlook.com;
 client-ip=160.33.194.231; helo=usculsndmail04v.am.sony.com;
From:   <Tim.Bird@sony.com>
To:     <joe@perches.com>, <brendanhiggins@google.com>
CC:     <shuah@kernel.org>, <sergey.senozhatsky.work@gmail.com>,
        <kunit-dev@googlegroups.com>, <linux-kernel@vger.kernel.org>,
        <linux-kselftest@vger.kernel.org>, <frowand.list@gmail.com>,
        <sboyd@kernel.org>, <pmladek@suse.com>,
        <sergey.senozhatsky@gmail.com>, <rostedt@goodmis.org>,
        <rdunlap@infradead.org>, <sfr@canb.auug.org.au>
Subject: RE: [PATCH v2] kunit: fix failure to build without printk
Thread-Topic: [PATCH v2] kunit: fix failure to build without printk
Thread-Index: AQHVXYOHSzY8I+qIqESnE7HuJlTJpKcQk8yAgAIK7gCAAMSnAIAA6NiAgAAj6AD//87t0A==
Date:   Fri, 30 Aug 2019 21:58:37 +0000
Message-ID: <ECADFF3FD767C149AD96A924E7EA6EAF977A8392@USCULXMSG01.am.sony.com>
References: <20190828093143.163302-1-brendanhiggins@google.com>
         <20190828094929.GA14038@jagdpanzerIV>
         <8b2d63bf-56cd-e8f5-e8ee-2891c2c1be8f@kernel.org>
         <f2d5b474411b2940d62198490f06e77890fbdb32.camel@perches.com>
         <20190830183821.GA30306@google.com>
 <bc688b00b2995e4b11229c3d4d90f532e00792c7.camel@perches.com>
In-Reply-To: <bc688b00b2995e4b11229c3d4d90f532e00792c7.camel@perches.com>
Accept-Language: en-US
Content-Language: en-US
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 30 Aug 2019 21:58:54.2298
 (UTC)
X-MS-Exchange-CrossTenant-Network-Message-Id: 7ae7006a-7942-4010-e3e1-08d72d95404e
X-MS-Exchange-CrossTenant-Id: 66c65d8a-9158-4521-a2d8-664963db48e4
X-MS-Exchange-CrossTenant-OriginalAttributedTenantConnectingIp: TenantId=66c65d8a-9158-4521-a2d8-664963db48e4;Ip=[160.33.194.231];Helo=[usculsndmail04v.am.sony.com]
X-MS-Exchange-CrossTenant-FromEntityHeader: HybridOnPrem
X-MS-Exchange-Transport-CrossTenantHeadersStamped: DM5PR13MB1834
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org


> -----Original Message-----
> From: Joe Perches
>=20
> On Fri, 2019-08-30 at 11:38 -0700, Brendan Higgins wrote:
> > On Thu, Aug 29, 2019 at 09:44:58PM -0700, Joe Perches wrote:
> > > On Thu, 2019-08-29 at 11:01 -0600, shuah wrote:
> > > > On 8/28/19 3:49 AM, Sergey Senozhatsky wrote:
> > > > > On (08/28/19 02:31), Brendan Higgins wrote:
> > > > > [..]
> > > > > > Previously KUnit assumed that printk would always be present,
> which is
> > > > > > not a valid assumption to make. Fix that by removing call to
> > > > > > vprintk_emit, and calling printk directly.
> > > > > >
> > > > > > Reported-by: Randy Dunlap <rdunlap@infradead.org>
> > > > > > Link: https://lore.kernel.org/linux-kselftest/0352fae9-564f-4a9=
7-
> 715a-fabe016259df@kernel.org/T/#t
> > > > > > Cc: Stephen Rothwell <sfr@canb.auug.org.au>
> > > > > > Cc: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
> > > > > > Signed-off-by: Brendan Higgins <brendanhiggins@google.com>
> > > > >
> > > > > [..]
> > > > >
> > > > > > -static void kunit_vprintk(const struct kunit *test,
> > > > > > -			  const char *level,
> > > > > > -			  struct va_format *vaf)
> > > > > > -{
> > > > > > -	kunit_printk_emit(level[1] - '0', "\t# %s: %pV", test->name,
> vaf);
> > > > > > -}
> > > > >
> > > > > This patch looks good to me. I like the removal of recursive
> > > > > vsprintf() (%pV).
> > > > >
> > > > > 	-ss
> > > > >
> > > >
> > > > Hi Sergey,
> > > >
> > > > What are the guidelines for using printk(). I recall some discussio=
n
> > > > about not using printk(). I am seeing the following from checkpatch
> > > > script:
> > > >
> > > >
> > > > WARNING: Prefer [subsystem eg: netdev]_level([subsystem]dev, ...
> then
> > > > dev_level(dev, ... then pr_level(...  to printk(KERN_LEVEL ...
> > > > #105: FILE: include/kunit/test.h:343:
> > > > +	printk(KERN_LEVEL "\t# %s: " fmt, (test)->name, ##__VA_ARGS__)
> > > >
> > > >
> > > > Is there supposed to be pr_level() - I can find dev_level()
> > > >
> > > > cc'ing Joe Perches for his feedback on this message recommending
> > > > pr_level() which isn't in 5.3.
> > >
> > > I don't care for pr_level or KERN_LEVEL in a printk.
> >
> > I don't think I follow, how does your version fix this?
> >
> > > I think this is somewhat overly complicated.
> > >
> > > I think I'd write it like:
> > > ---
> > >  include/kunit/test.h | 11 ++++-----
> > >  kunit/test.c         | 69 ++++++++++++++++--------------------------=
----------
> > >  2 files changed, 26 insertions(+), 54 deletions(-)
> > >
> > > diff --git a/include/kunit/test.h b/include/kunit/test.h
> > > index 8b7eb03d4971..aa4abf0a22a5 100644
> > > --- a/include/kunit/test.h
> > > +++ b/include/kunit/test.h
> > > @@ -339,9 +339,8 @@ static inline void *kunit_kzalloc(struct kunit *t=
est,
> size_t size, gfp_t gfp)
> > >
> > >  void kunit_cleanup(struct kunit *test);
> > >
> > > -void __printf(3, 4) kunit_printk(const char *level,
> > > -				 const struct kunit *test,
> > > -				 const char *fmt, ...);
> > > +__printf(2, 3)
> > > +void kunit_printk(const struct kunit *test, const char *fmt, ...);
> > >
> > >  /**
> > >   * kunit_info() - Prints an INFO level message associated with @test=
.
> > > @@ -353,7 +352,7 @@ void __printf(3, 4) kunit_printk(const char *leve=
l,
> > >   * Takes a variable number of format parameters just like printk().
> > >   */
> > >  #define kunit_info(test, fmt, ...) \
> > > -	kunit_printk(KERN_INFO, test, fmt, ##__VA_ARGS__)
> > > +	kunit_printk(test, KERN_INFO fmt, ##__VA_ARGS__)
> > >
> > >  /**
> > >   * kunit_warn() - Prints a WARN level message associated with @test.
> > > @@ -364,7 +363,7 @@ void __printf(3, 4) kunit_printk(const char *leve=
l,
> > >   * Prints a warning level message.
> > >   */
> > >  #define kunit_warn(test, fmt, ...) \
> > > -	kunit_printk(KERN_WARNING, test, fmt, ##__VA_ARGS__)
> > > +	kunit_printk(test, KERN_WARNING fmt, ##__VA_ARGS__)
> > >
> > >  /**
> > >   * kunit_err() - Prints an ERROR level message associated with @test=
.
> > > @@ -375,7 +374,7 @@ void __printf(3, 4) kunit_printk(const char *leve=
l,
> > >   * Prints an error level message.
> > >   */
> > >  #define kunit_err(test, fmt, ...) \
> > > -	kunit_printk(KERN_ERR, test, fmt, ##__VA_ARGS__)
> > > +	kunit_printk(test, KERN_ERR fmt, ##__VA_ARGS__)
> > >
> > >  /**
> > >   * KUNIT_SUCCEED() - A no-op expectation. Only exists for code clari=
ty.
> > > diff --git a/kunit/test.c b/kunit/test.c
> > > index b2ca9b94c353..ddb9bffb5a5d 100644
> > > --- a/kunit/test.c
> > > +++ b/kunit/test.c
> > > @@ -16,40 +16,6 @@ static void kunit_set_failure(struct kunit *test)
> > >  	WRITE_ONCE(test->success, false);
> > >  }
> > >
> > > -static int kunit_vprintk_emit(int level, const char *fmt, va_list ar=
gs)
> > > -{
> > > -	return vprintk_emit(0, level, NULL, 0, fmt, args);
> > > -}
> > > -
> > > -static int kunit_printk_emit(int level, const char *fmt, ...)
> > > -{
> > > -	va_list args;
> > > -	int ret;
> > > -
> > > -	va_start(args, fmt);
> > > -	ret =3D kunit_vprintk_emit(level, fmt, args);
> > > -	va_end(args);
> > > -
> > > -	return ret;
> > > -}
> > > -
> > > -static void kunit_vprintk(const struct kunit *test,
> > > -			  const char *level,
> > > -			  struct va_format *vaf)
> > > -{
> > > -	kunit_printk_emit(level[1] - '0', "\t# %s: %pV", test->name, vaf);
> > > -}
> > > -
> > > -static void kunit_print_tap_version(void)
> > > -{
> > > -	static bool kunit_has_printed_tap_version;
> > > -
> > > -	if (!kunit_has_printed_tap_version) {
> > > -		kunit_printk_emit(LOGLEVEL_INFO, "TAP version 14\n");
> > > -		kunit_has_printed_tap_version =3D true;
> > > -	}
> > > -}
> > > -
> > >  static size_t kunit_test_cases_len(struct kunit_case *test_cases)
> > >  {
> > >  	struct kunit_case *test_case;
> > > @@ -63,11 +29,9 @@ static size_t kunit_test_cases_len(struct kunit_ca=
se
> *test_cases)
> > >
> > >  static void kunit_print_subtest_start(struct kunit_suite *suite)
> > >  {
> > > -	kunit_print_tap_version();
> > > -	kunit_printk_emit(LOGLEVEL_INFO, "\t# Subtest: %s\n", suite-
> >name);
> > > -	kunit_printk_emit(LOGLEVEL_INFO,
> > > -			  "\t1..%zd\n",
> > > -			  kunit_test_cases_len(suite->test_cases));
> > > +	pr_info_once("TAP version 14\n");
> > > +	pr_info("\t# Subtest: %s\n", suite->name);
> > > +	pr_info("\t1..%zd\n", kunit_test_cases_len(suite->test_cases));
> > >  }
> > >
> > >  static void kunit_print_ok_not_ok(bool should_indent,
> > > @@ -87,9 +51,8 @@ static void kunit_print_ok_not_ok(bool
> should_indent,
> > >  	else
> > >  		ok_not_ok =3D "not ok";
> > >
> > > -	kunit_printk_emit(LOGLEVEL_INFO,
> > > -			  "%s%s %zd - %s\n",
> > > -			  indent, ok_not_ok, test_number, description);
> > > +	pr_info("%s%s %zd - %s\n",
> > > +		indent, ok_not_ok, test_number, description);
> > >  }
> > >
> > >  static bool kunit_suite_has_succeeded(struct kunit_suite *suite)
> > > @@ -133,11 +96,11 @@ static void kunit_print_string_stream(struct kun=
it
> *test,
> > >  		kunit_err(test,
> > >  			  "Could not allocate buffer, dumping stream:\n");
> > >  		list_for_each_entry(fragment, &stream->fragments, node) {
> > > -			kunit_err(test, fragment->fragment);
> > > +			kunit_err(test, "%s", fragment->fragment);
> > >  		}
> > >  		kunit_err(test, "\n");
> > >  	} else {
> > > -		kunit_err(test, buf);
> > > +		kunit_err(test, "%s", buf);
> > >  		kunit_kfree(test, buf);
> > >  	}
> > >  }
> > > @@ -505,19 +468,29 @@ void kunit_cleanup(struct kunit *test)
> > >  	}
> > >  }
> > >
> > > -void kunit_printk(const char *level,
> > > -		  const struct kunit *test,
> > > -		  const char *fmt, ...)
> > > +void kunit_printk(const struct kunit *test, const char *fmt, ...)
> > >  {
> > > +	char lvl[PRINTK_MAX_SINGLE_HEADER_LEN + 1] =3D "\0";
> > >  	struct va_format vaf;
> > >  	va_list args;
> > > +	int kern_level;
> > >
> > >  	va_start(args, fmt);
> > >
> > > +	while ((kern_level =3D printk_get_level(fmt)) !=3D 0) {
> > > +		size_t size =3D printk_skip_level(fmt) - fmt;
> > > +
> > > +		if (kern_level >=3D '0' && kern_level <=3D '7') {
> > > +			memcpy(lvl, fmt,  size);
> > > +			lvl[size] =3D '\0';
> > > +		}
> > > +		fmt +=3D size;
> > > +	}
> > > +
> > >  	vaf.fmt =3D fmt;
> > >  	vaf.va =3D &args;
> > >
> > > -	kunit_vprintk(test, level, &vaf);
> > > +	printk("%s\t# %s %pV\n", lvl, test->name, &vaf);
> > >
> > >  	va_end(args);
> > >  }
> >
> > How is this simpler?
> >
> > If we are okay with dynamically adding the KERN_<LEVEL> and %pV (and I
> > don't think that Sergey is),
>=20
> Sergey may well be in the minority overall as %pV
> is now very frequently
> used throughout the kernel.
>=20
> $ git grep "%pV" | wc -l
> 241

Hmm.  IMHO %pV should be avoided if possible.  Just because people are
doing it doesn't mean it should be used when it is not necessary.

>=20
>  then wouldn't it be easier to pass in the
> > kernel level as a separate parameter and then strip off all printk
> > headers like this:
>=20
> Depends on whether or not you care for overall
> object size.  Consolidated formats with the
> embedded KERN_<LEVEL> like suggested are smaller
> overall object size.

This is an argument I can agree with.  I'm generally in favor of
things that lessen kernel size creep. :-)

 -- Tim

>=20
> This style is also already used in the kernel.
>=20
> > I don't know. I am clearly not an expert on this topic, but I don't see
> > the merit of the while loop you added above or dropping the level param=
.
>=20
> The while use is only to avoid misuses with consecutive
> KERN_<LEVEL> formats, which had happened in the past.