From patchwork Wed May 31 09:50:26 2017 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Hans Verkuil (hansverk)" X-Patchwork-Id: 41557 X-Patchwork-Delegate: hverkuil@xs4all.nl Received: from mail.tu-berlin.de ([130.149.7.33]) by www.linuxtv.org with esmtp (Exim 4.84_2) (envelope-from ) id 1dG0RS-0005BR-Sh; Wed, 31 May 2017 10:01:27 +0000 X-tubIT-Incoming-IP: 209.132.180.67 Received: from vger.kernel.org ([209.132.180.67]) by mail.tu-berlin.de (exim-4.89/mailfrontend-7) with esmtp id 1dG0RL-0006qd-3B; Wed, 31 May 2017 12:01:26 +0200 Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751023AbdEaKAk (ORCPT + 1 other); Wed, 31 May 2017 06:00:40 -0400 Received: from aer-iport-3.cisco.com ([173.38.203.53]:41530 "EHLO aer-iport-3.cisco.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751015AbdEaKAk (ORCPT ); Wed, 31 May 2017 06:00:40 -0400 X-Greylist: delayed 608 seconds by postgrey-1.27 at vger.kernel.org; Wed, 31 May 2017 06:00:39 EDT DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=cisco.com; i=@cisco.com; l=5104; q=dns/txt; s=iport; t=1496224839; x=1497434439; h=to:from:subject:message-id:date:mime-version: content-transfer-encoding; bh=CReviQDNumqOWD+0ZxOyksC6FEbkX4IAuvxiZQRrKGs=; b=ZtMHkB0ArR1H/bkqUBE3KMscEd0NNez0V8L7/wY06h/y5QizunpXq60i MGECrf4JrqMow0UE2SfTC2Sue6LPDvs939U3Ilapen/FAwUCzoqnsx81b DD1793D61XPS7jChDwLXC1O3mrBak5QQGNBxVwkc5Pa9eqhEW6kvczbmv 4=; X-IronPort-Anti-Spam-Filtered: true X-IronPort-Anti-Spam-Result: =?us-ascii?q?A0AGAQBEkS5Z/xbLJq1cGgEBAQECAQEBA?= =?us-ascii?q?QgBAQEBhUSDcooYc6Z0gg+JQhgBAgEBAQEBAQFrKIVCBIEHAiYCXw0GAgEBiia?= =?us-ascii?q?bVpALgWw6i1EBAQEHAgElgQuFVoFgK4pvgmAFiUeGYo16kyiLC4ZqApROHziBC?= =?us-ascii?q?jAhCBsVRoUDHIFlPjaJUwEBAQ?= X-IronPort-AV: E=Sophos;i="5.38,422,1491264000"; d="scan'208";a="653223089" Received: from aer-iport-nat.cisco.com (HELO aer-core-2.cisco.com) ([173.38.203.22]) by aer-iport-3.cisco.com with ESMTP/TLS/DHE-RSA-AES256-GCM-SHA384; 31 May 2017 09:50:27 +0000 Received: from [10.47.79.81] ([10.47.79.81]) (authenticated bits=0) by aer-core-2.cisco.com (8.14.5/8.14.5) with ESMTP id v4V9oQGZ016503 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES128-SHA bits=128 verify=NO) for ; Wed, 31 May 2017 09:50:27 GMT To: Linux Media Mailing List From: Hans Verkuil Subject: [PATCH] cec: improve debug messages Message-ID: <6e3b5b64-ab7b-afac-882d-144c49d8ac82@cisco.com> Date: Wed, 31 May 2017 11:50:26 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.6.0 MIME-Version: 1.0 X-Authenticated-User: hansverk Sender: linux-media-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-media@vger.kernel.org X-PMX-Version: 6.0.0.2142326, Antispam-Engine: 2.7.2.2107409, Antispam-Data: 2017.5.24.82116 X-PMX-Spam: Gauge=IIIIIIII, Probability=8%, Report=' HTML_00_01 0.05, HTML_00_10 0.05, BODY_SIZE_4000_4999 0, BODY_SIZE_5000_LESS 0, BODY_SIZE_7000_LESS 0, DKIM_SIGNATURE 0, NO_URI_HTTPS 0, __ANY_URI 0, __CT 0, __CTE 0, __CT_TEXT_PLAIN 0, __HAS_FROM 0, __HAS_LIST_ID 0, __HAS_MSGID 0, __HAS_X_MAILING_LIST 0, __INT_PROD_TV 0, __MIME_TEXT_ONLY 0, __MIME_TEXT_P 0, __MIME_TEXT_P1 0, __MIME_VERSION 0, __MOZILLA_USER_AGENT 0, __NO_HTML_TAG_RAW 0, __SANE_MSGID 0, __STOCK_PHRASE_7 0, __SUBJ_ALPHA_END 0, __SUBJ_ALPHA_NEGATE 0, __TO_MALFORMED_2 0, __TO_NAME 0, __TO_NAME_DIFF_FROM_ACC 0, __TO_REAL_NAMES 0, __URI_NO_WWW 0, __URI_NS , __USER_AGENT 0' - use __func__ instead of writing the full function name - drop debug message in cec_config_log_addr since the same information will be reported later - use debug level 1 for errors and infrequent events, use level 2 for debugging CEC message traffic - log when a transmit is retried, very useful to know when debugging - debug messages now all start with lower case Signed-off-by: Hans Verkuil --- drivers/media/cec/cec-adap.c | 28 ++++++++++++++++------------ 1 file changed, 16 insertions(+), 12 deletions(-) diff --git a/drivers/media/cec/cec-adap.c b/drivers/media/cec/cec-adap.c index f5fe01c9da8a..f85eae710043 100644 --- a/drivers/media/cec/cec-adap.c +++ b/drivers/media/cec/cec-adap.c @@ -392,7 +392,7 @@ int cec_thread_func(void *_adap) * happen and is an indication of a faulty CEC adapter * driver, or the CEC bus is in some weird state. */ - dprintk(0, "message %*ph timed out!\n", + dprintk(0, "%s: message %*ph timed out!\n", __func__, adap->transmitting->msg.len, adap->transmitting->msg.msg); /* Just give up on this. */ @@ -468,7 +468,7 @@ void cec_transmit_done(struct cec_adapter *adap, u8 status, u8 arb_lost_cnt, struct cec_msg *msg; u64 ts = ktime_get_ns(); - dprintk(2, "cec_transmit_done %02x\n", status); + dprintk(2, "%s: status %02x\n", __func__, status); mutex_lock(&adap->lock); data = adap->transmitting; if (!data) { @@ -477,7 +477,8 @@ void cec_transmit_done(struct cec_adapter *adap, u8 status, u8 arb_lost_cnt, * unplugged while the transmit is ongoing. Ignore this * transmit in that case. */ - dprintk(1, "cec_transmit_done without an ongoing transmit!\n"); + dprintk(1, "%s was called without an ongoing transmit!\n", + __func__); goto unlock; } @@ -504,6 +505,12 @@ void cec_transmit_done(struct cec_adapter *adap, u8 status, u8 arb_lost_cnt, !(status & (CEC_TX_STATUS_MAX_RETRIES | CEC_TX_STATUS_OK))) { /* Retry this message */ data->attempts--; + if (msg->timeout) + dprintk(2, "retransmit: %*ph (attempts: %d, wait for 0x%02x)\n", + msg->len, msg->msg, data->attempts, msg->reply); + else + dprintk(2, "retransmit: %*ph (attempts: %d)\n", + msg->len, msg->msg, data->attempts); /* Add the message in front of the transmit queue */ list_add(&data->list, &adap->transmit_queue); adap->transmit_queue_sz++; @@ -911,7 +918,7 @@ void cec_received_msg(struct cec_adapter *adap, struct cec_msg *msg) memset(msg->msg + msg->len, 0, sizeof(msg->msg) - msg->len); mutex_lock(&adap->lock); - dprintk(2, "cec_received_msg: %*ph\n", msg->len, msg->msg); + dprintk(2, "%s: %*ph\n", __func__, msg->len, msg->msg); /* Check if this message was for us (directed or broadcast). */ if (!cec_msg_is_broadcast(msg)) @@ -1112,9 +1119,6 @@ static int cec_config_log_addr(struct cec_adapter *adap, las->log_addr[idx] = log_addr; las->log_addr_mask |= 1 << log_addr; adap->phys_addrs[log_addr] = adap->phys_addr; - - dprintk(2, "claimed addr %d (%d)\n", log_addr, - las->primary_device_type[idx]); return 1; } @@ -1300,7 +1304,7 @@ static int cec_config_thread_func(void *arg) /* Report Physical Address */ cec_msg_report_physical_addr(&msg, adap->phys_addr, las->primary_device_type[i]); - dprintk(2, "config: la %d pa %x.%x.%x.%x\n", + dprintk(1, "config: la %d pa %x.%x.%x.%x\n", las->log_addr[i], cec_phys_addr_exp(adap->phys_addr)); cec_transmit_msg_fh(adap, &msg, NULL, false); @@ -1534,12 +1538,12 @@ int __cec_s_log_addrs(struct cec_adapter *adap, if (log_addrs->num_log_addrs == 2) { if (!(type_mask & ((1 << CEC_LOG_ADDR_TYPE_AUDIOSYSTEM) | (1 << CEC_LOG_ADDR_TYPE_TV)))) { - dprintk(1, "Two LAs is only allowed for audiosystem and TV\n"); + dprintk(1, "two LAs is only allowed for audiosystem and TV\n"); return -EINVAL; } if (!(type_mask & ((1 << CEC_LOG_ADDR_TYPE_PLAYBACK) | (1 << CEC_LOG_ADDR_TYPE_RECORD)))) { - dprintk(1, "An audiosystem/TV can only be combined with record or playback\n"); + dprintk(1, "an audiosystem/TV can only be combined with record or playback\n"); return -EINVAL; } } @@ -1653,7 +1657,7 @@ static int cec_receive_notify(struct cec_adapter *adap, struct cec_msg *msg, bool from_unregistered = init_laddr == 0xf; struct cec_msg tx_cec_msg = { }; - dprintk(1, "cec_receive_notify: %*ph\n", msg->len, msg->msg); + dprintk(2, "%s: %*ph\n", __func__, msg->len, msg->msg); /* If this is a CDC-Only device, then ignore any non-CDC messages */ if (cec_is_cdc_only(&adap->log_addrs) && @@ -1722,7 +1726,7 @@ static int cec_receive_notify(struct cec_adapter *adap, struct cec_msg *msg, if (!from_unregistered) adap->phys_addrs[init_laddr] = pa; - dprintk(1, "Reported physical address %x.%x.%x.%x for logical address %d\n", + dprintk(1, "reported physical address %x.%x.%x.%x for logical address %d\n", cec_phys_addr_exp(pa), init_laddr); break; }