From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S932678AbcGOLLe (ORCPT <rfc822;w@1wt.eu>);
	Fri, 15 Jul 2016 07:11:34 -0400
Received: from mail.linuxfoundation.org ([140.211.169.12]:54399 "EHLO
	mail.linuxfoundation.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S932517AbcGOLLb (ORCPT
	<rfc822;linux-kernel@vger.kernel.org>);
	Fri, 15 Jul 2016 07:11:31 -0400
Date: Fri, 15 Jul 2016 20:11:41 +0900
From: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
To: Felipe Balbi <felipe.balbi@linux.intel.com>
Cc: Bin Gao <bin.gao@linux.intel.com>,
        Heikki Krogerus <heikki.krogerus@linux.intel.com>,
        linux-usb@vger.kernel.org, linux-kernel@vger.kernel.org,
        Bin Gao <bin.gao@intel.com>,
        Chandra Sekhar Anagani <chandra.sekhar.anagani@intel.com>
Subject: Re: [PATCH 1/2] usb: typec: Add USB Power Delivery sink port support
Message-ID: <20160715111141.GB23645@kroah.com>
References: <20160715021405.GB128987@worksta>
 <87mvljgp9n.fsf@linux.intel.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <87mvljgp9n.fsf@linux.intel.com>
User-Agent: Mutt/1.6.2 (2016-07-01)
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

On Fri, Jul 15, 2016 at 01:38:12PM +0300, Felipe Balbi wrote:
> 
> Hi,
> 
> Bin Gao <bin.gao@linux.intel.com> writes:
> > +static void print_message(int port, bool is_cmsg, u8 msg, bool recv)
> > +{
> > +	pr_info("sink port %d: %s message %s %s\n", port,
> > +				is_cmsg ? "Control" : "Data",
> > +				msg_to_string(is_cmsg, msg),
> > +		 recv ? "received" : "sent(wait GOODCRC)");
> > +}
> 
> this is problematic. By default, we're all using 115200 8N1 baud
> rate. This message alone prints anywhere from 50 to 100 characters (I
> didn't really count properly, these are rough numbers), and that takes:
> 
> n50chars_time = 50 / (115200 / 10) = 4.3ms
> n100chars_time = 100 / (115200 / 10) = 8.6ms
> 
> Considering you have 30ms to reply with Power Request after GoodCRC, and
> considering you're printing several of these messages, they become
> really expensive and eat up valuable time from tSenderReply.

printk() should be async, so it shouldn't be that big of a deal.

What is wrong is that this isn't using dev_info().

> This should really be a pr_debug() or, better yet, a tracepoint.

Yes, that would be best (dev_dbg() or a tracepoint.)

thanks,

greg k-h