Re: [PATCH V2] Enhance logging for Shared Transport - TI driver

Mircea Gherzan
2012-03-16T21:14:13Z

Am 16.03.2012 18:58, schrieb alexandrasava18@gmail.com:
> From: Alexandra Sava <alexandrasava18@gmail.com>
>
> * reduced verbosity
> * replaced pr_* with dev_* where possible
> * fixed yoda conditions
>
> Signed-off-by: Alexandra Sava <alexandrasava18@gmail.com>
> Cc: Daniel Baluta <daniel.baluta@gmail.com>
> Cc: Mircea Gherzan <mgherzan@gmail.com>
> ---
> Changes since v1:
> * removed debug_mask module parameter

IMHO a debug mask or even just a debug switch is still needed.

> * removed custome logging functions

This is actually worse than the first iteration:
* no consistent prefix
* quite the same verbosity and no control over it.

Here's what I get now when loading btwilink:

[ 30.473663] kim kim: sysfs entries created
[ 30.478698] kim kim: debugfs entries created
[ 30.491149] Bluetooth: Bluetooth Driver for TI WiLink - Version 1.0
[ 30.508636] chnl_id list empty :4
[ 30.677947] kim kim: Line discipline installed
[ 31.621459] kim kim: Loaded TIInit_7.2.31.bts firmware
[ 31.621459] Add new channel: id - 4
[ 31.631134] Add new channel: id - 2
[ 31.633911] Add new channel: id - 3
[ 31.641052] chip/interface misbehavior dropping frame starting with 0x01
[ 41.636505] Remove channel: id - 3
[ 41.636505] Remove channel: id - 2
[ 41.643951] Remove channel: id - 4
[ 41.652465] chnl_id list empty :4
[ 41.817138] kim kim: Line discipline installed
[ 42.735137] kim kim: Loaded TIInit_7.2.31.bts firmware
[ 42.740783] Add new channel: id - 4
[ 42.744842] Add new channel: id - 2
[ 42.748657] Add new channel: id - 3
[ 42.753204] chip/interface misbehavior dropping frame starting with 0x01
[ 52.776763] Remove channel: id - 3
[ 52.780853] Remove channel: id - 2
[ 52.782409] Remove channel: id - 4

And I would like too see only something like this:

[ 30.491149] Bluetooth: Bluetooth Driver for TI WiLink - Version 1.0
[ 30.677947] st_drv: Line discipline installed
[ 31.621459] st_drv: Loaded TIInit_7.2.31.bts firmware

> drivers/misc/ti-st/st_core.c | 91 +++++++++++----------------------------
> drivers/misc/ti-st/st_kim.c | 98 +++++++++++++++++-------------------------
> drivers/misc/ti-st/st_ll.c | 17 +++-----
> 3 files changed, 70 insertions(+), 136 deletions(-)
>
> diff --git a/drivers/misc/ti-st/st_core.c b/drivers/misc/ti-st/st_core.c
> index 2b62232..9a0e070 100644
> --- a/drivers/misc/ti-st/st_core.c
> +++ b/drivers/misc/ti-st/st_core.c
> @@ -19,7 +19,6 @@
> *
> */
>
> -#define pr_fmt(fmt) "(stc): " fmt
> #include <linux/module.h>
> #include <linux/kernel.h>
> #include <linux/init.h>
> @@ -40,7 +39,7 @@ void (*st_recv) (void*, const unsigned char*, long);
> static void add_channel_to_table(struct st_data_s *st_gdata,
> struct st_proto_s *new_proto)
> {
> - pr_info("%s: id %d\n", __func__, new_proto->chnl_id);
> + pr_info("Add new channel: id - %d\n", new_proto->chnl_id);
> /* list now has the channel id as index itself */
> st_gdata->list[new_proto->chnl_id] = new_proto;
> st_gdata->is_registered[new_proto->chnl_id] = true;
> @@ -49,7 +48,7 @@ static void add_channel_to_table(struct st_data_s *st_gdata,
> static void remove_channel_from_table(struct st_data_s *st_gdata,
> struct st_proto_s *proto)
> {
> - pr_info("%s: id %d\n", __func__, proto->chnl_id);
> + pr_info("Remove channel: id - %d\n", proto->chnl_id);
> /* st_gdata->list[proto->chnl_id] = NULL; */
> st_gdata->is_registered[proto->chnl_id] = false;
> }
> @@ -102,8 +101,6 @@ int st_int_write(struct st_data_s *st_gdata,
> */
> void st_send_frame(unsigned char chnl_id, struct st_data_s *st_gdata)
> {
> - pr_debug(" %s(prot:%d) ", __func__, chnl_id);
> -
> if (unlikely
> (st_gdata == NULL || st_gdata->rx_skb == NULL
> || st_gdata->is_registered[chnl_id] == false)) {
> @@ -122,12 +119,12 @@ void st_send_frame(unsigned char chnl_id, struct st_data_s *st_gdata)
> (st_gdata->list[chnl_id]->recv
> (st_gdata->list[chnl_id]->priv_data, st_gdata->rx_skb)
> != 0)) {
> - pr_err(" proto stack %d's ->recv failed", chnl_id);
> + pr_err("proto stack %d's ->recv failed", chnl_id);
> kfree_skb(st_gdata->rx_skb);
> return;
> }
> } else {
> - pr_err(" proto stack %d's ->recv null", chnl_id);
> + pr_err("proto stack %d's ->recv null", chnl_id);
> kfree_skb(st_gdata->rx_skb);
> }
> return;
> @@ -143,14 +140,13 @@ void st_send_frame(unsigned char chnl_id, struct st_data_s *st_gdata)
> void st_reg_complete(struct st_data_s *st_gdata, char err)
> {
> unsigned char i = 0;
> - pr_info(" %s ", __func__);
> +
> for (i = 0; i < ST_MAX_CHANNELS; i++) {
> if (likely(st_gdata != NULL &&
> st_gdata->is_registered[i] == true &&
> st_gdata->list[i]->reg_complete_cb != NULL)) {
> st_gdata->list[i]->reg_complete_cb
> (st_gdata->list[i]->priv_data, err);
> - pr_info("protocol %d's cb sent %d\n", i, err);
> if (err) { /* cleanup registered protocol */
> st_gdata->protos_registered--;
> st_gdata->is_registered[i] = false;
> @@ -164,8 +160,6 @@ static inline int st_check_data_len(struct st_data_s *st_gdata,
> {
> int room = skb_tailroom(st_gdata->rx_skb);
>
> - pr_debug("len %d room %d", len, room);
> -
> if (!len) {
> /* Received packet has only packet header and
> * has zero length payload. So, ask ST CORE to
> @@ -177,7 +171,7 @@ static inline int st_check_data_len(struct st_data_s *st_gdata,
> /* Received packet's payload length is larger.
> * We can't accommodate it in created skb.
> */
> - pr_err("Data length is too large len %d room %d", len,
> + pr_err("Data length is too large: len - %d room - %d", len,
> room);
> kfree_skb(st_gdata->rx_skb);
> } else {
> @@ -246,14 +240,10 @@ void st_int_recv(void *disc_data,
> ptr = (char *)data;
> /* tty_receive sent null ? */
> if (unlikely(ptr == NULL) || (st_gdata == NULL)) {
> - pr_err(" received null from TTY ");
> + pr_err("Received null from TTY");
> return;
> }
>
> - pr_debug("count %ld rx_state %ld"
> - "rx_count %ld", count, st_gdata->rx_state,
> - st_gdata->rx_count);
> -
> spin_lock_irqsave(&st_gdata->lock, flags);
> /* Decode received bytes here */
> while (count) {
> @@ -285,22 +275,16 @@ void st_int_recv(void *disc_data,
> plen =
> &st_gdata->rx_skb->data
> [proto->offset_len_in_hdr];
> - pr_debug("plen pointing to %x\n", *plen);
> if (proto->len_size == 1)/* 1 byte len field */
> payload_len = *(unsigned char *)plen;
> else if (proto->len_size == 2)
> payload_len =
> __le16_to_cpu(*(unsigned short *)plen);
> else
> - pr_info("%s: invalid length "
> - "for id %d\n",
> - __func__, proto->chnl_id);
> st_check_data_len(st_gdata, proto->chnl_id,
> payload_len);
> - pr_debug("off %d, pay len %d\n",
> - proto->offset_len_in_hdr, payload_len);
> continue;
> - } /* end of switch rx_state */
> + }
> }
>
> /* end of if rx_count */
> @@ -310,7 +294,6 @@ void st_int_recv(void *disc_data,
> case LL_SLEEP_IND:
> case LL_SLEEP_ACK:
> case LL_WAKE_UP_IND:
> - pr_debug("PM packet");
> /* this takes appropriate action based on
> * sleep state received --
> */
> @@ -327,8 +310,6 @@ void st_int_recv(void *disc_data,
> count--;
> continue;
> case LL_WAKE_UP_ACK:
> - pr_debug("PM packet");
> -
> spin_unlock_irqrestore(&st_gdata->lock, flags);
> /* wake up ack received */
> st_wakeup_ack(st_gdata, *ptr);
> @@ -344,7 +325,6 @@ void st_int_recv(void *disc_data,
> pr_err("chip/interface misbehavior dropping"
> " frame starting with 0x%02x", type);
> goto done;
> -
> }
> st_gdata->rx_skb = alloc_skb(
> st_gdata->list[type]->max_frame_size,
> @@ -352,19 +332,17 @@ void st_int_recv(void *disc_data,
> skb_reserve(st_gdata->rx_skb,
> st_gdata->list[type]->reserve);
> /* next 2 required for BT only */
> - st_gdata->rx_skb->cb[0] = type; /*pkt_type*/
> - st_gdata->rx_skb->cb[1] = 0; /*incoming*/
> + st_gdata->rx_skb->cb[0] = type; /* pkt_type */
> + st_gdata->rx_skb->cb[1] = 0; /* incoming */
> st_gdata->rx_chnl = *ptr;
> st_gdata->rx_state = ST_W4_HEADER;
> st_gdata->rx_count = st_gdata->list[type]->hdr_len;
> - pr_debug("rx_count %ld\n", st_gdata->rx_count);
> };
> ptr++;
> count--;
> }
> done:
> spin_unlock_irqrestore(&st_gdata->lock, flags);
> - pr_debug("done %s", __func__);
> return;
> }
>
> @@ -378,7 +356,6 @@ struct sk_buff *st_int_dequeue(struct st_data_s *st_gdata)
> {
> struct sk_buff *returning_skb;
>
> - pr_debug("%s", __func__);
> if (st_gdata->tx_skb != NULL) {
> returning_skb = st_gdata->tx_skb;
> st_gdata->tx_skb = NULL;
> @@ -400,7 +377,6 @@ void st_int_enqueue(struct st_data_s *st_gdata, struct sk_buff *skb)
> {
> unsigned long flags = 0;
>
> - pr_debug("%s", __func__);
> spin_lock_irqsave(&st_gdata->lock, flags);
>
> switch (st_ll_getstate(st_gdata)) {
> @@ -428,7 +404,6 @@ void st_int_enqueue(struct st_data_s *st_gdata, struct sk_buff *skb)
> }
>
> spin_unlock_irqrestore(&st_gdata->lock, flags);
> - pr_debug("done %s", __func__);
> return;
> }
>
> @@ -442,10 +417,9 @@ void st_tx_wakeup(struct st_data_s *st_data)
> {
> struct sk_buff *skb;
> unsigned long flags; /* for irq save flags */
> - pr_debug("%s", __func__);
> +
> /* check for sending & set flag sending here */
> if (test_and_set_bit(ST_TX_SENDING, &st_data->tx_state)) {
> - pr_debug("ST already sending");
> /* keep sending */
> set_bit(ST_TX_WAKEUP, &st_data->tx_state);
> return;
> @@ -504,7 +478,6 @@ long st_register(struct st_proto_s *new_proto)
> unsigned long flags = 0;
>
> st_kim_ref(&st_gdata, 0);
> - pr_info("%s(%d) ", __func__, new_proto->chnl_id);
> if (st_gdata == NULL || new_proto == NULL || new_proto->recv == NULL
> || new_proto->reg_complete_cb == NULL) {
> pr_err("gdata/new_proto/recv or reg_complete_cb not ready");
> @@ -525,7 +498,7 @@ long st_register(struct st_proto_s *new_proto)
> spin_lock_irqsave(&st_gdata->lock, flags);
>
> if (test_bit(ST_REG_IN_PROGRESS, &st_gdata->st_state)) {
> - pr_info(" ST_REG_IN_PROGRESS:%d ", new_proto->chnl_id);
> + pr_info("ST_REG_IN_PROGRESS:%d", new_proto->chnl_id);
> /* fw download in progress */
>
> add_channel_to_table(st_gdata, new_proto);
> @@ -536,7 +509,7 @@ long st_register(struct st_proto_s *new_proto)
> spin_unlock_irqrestore(&st_gdata->lock, flags);
> return -EINPROGRESS;
> } else if (st_gdata->protos_registered == ST_EMPTY) {
> - pr_info(" chnl_id list empty :%d ", new_proto->chnl_id);
> + pr_info("chnl_id list empty :%d", new_proto->chnl_id);
> set_bit(ST_REG_IN_PROGRESS, &st_gdata->st_state);
> st_recv = st_kim_recv;
>
> @@ -554,7 +527,7 @@ long st_register(struct st_proto_s *new_proto)
> clear_bit(ST_REG_IN_PROGRESS, &st_gdata->st_state);
> if ((st_gdata->protos_registered != ST_EMPTY) &&
> (test_bit(ST_REG_PENDING, &st_gdata->st_state))) {
> - pr_err(" KIM failure complete callback ");
> + pr_err("KIM failure complete callback");
> st_reg_complete(st_gdata, err);
> clear_bit(ST_REG_PENDING, &st_gdata->st_state);
> }
> @@ -571,7 +544,6 @@ long st_register(struct st_proto_s *new_proto)
> */
> if ((st_gdata->protos_registered != ST_EMPTY) &&
> (test_bit(ST_REG_PENDING, &st_gdata->st_state))) {
> - pr_debug(" call reg complete callback ");
> st_reg_complete(st_gdata, 0);
> }
> clear_bit(ST_REG_PENDING, &st_gdata->st_state);
> @@ -580,7 +552,7 @@ long st_register(struct st_proto_s *new_proto)
> * since the above check is old
> */
> if (st_gdata->is_registered[new_proto->chnl_id] == true) {
> - pr_err(" proto %d already registered ",
> + pr_err("proto %d already registered",
> new_proto->chnl_id);
> spin_unlock_irqrestore(&st_gdata->lock, flags);
> return -EALREADY;
> @@ -602,7 +574,6 @@ long st_register(struct st_proto_s *new_proto)
> spin_unlock_irqrestore(&st_gdata->lock, flags);
> return err;
> }
> - pr_debug("done %s(%d) ", __func__, new_proto->chnl_id);
> }
> EXPORT_SYMBOL_GPL(st_register);
>
> @@ -615,18 +586,18 @@ long st_unregister(struct st_proto_s *proto)
> unsigned long flags = 0;
> struct st_data_s *st_gdata;
>
> - pr_debug("%s: %d ", __func__, proto->chnl_id);
> + pr_debug("Unregister protocol: chnl %d ", proto->chnl_id);
>
> st_kim_ref(&st_gdata, 0);
> if (!st_gdata || proto->chnl_id >= ST_MAX_CHANNELS) {
> - pr_err(" chnl_id %d not supported", proto->chnl_id);
> + pr_err("chnl_id %d not supported", proto->chnl_id);
> return -EPROTONOSUPPORT;
> }
>
> spin_lock_irqsave(&st_gdata->lock, flags);
>
> if (st_gdata->is_registered[proto->chnl_id] == false) {
> - pr_err(" chnl_id %d not registered", proto->chnl_id);
> + pr_err("chnl_id %d not registered", proto->chnl_id);
> spin_unlock_irqrestore(&st_gdata->lock, flags);
> return -EPROTONOSUPPORT;
> }
> @@ -641,8 +612,6 @@ long st_unregister(struct st_proto_s *proto)
>
> if ((st_gdata->protos_registered == ST_EMPTY) &&
> (!test_bit(ST_REG_PENDING, &st_gdata->st_state))) {
> - pr_info(" all chnl_ids unregistered ");
> -
> /* stop traffic on tty */
> if (st_gdata->tty) {
> tty_ldisc_flush(st_gdata->tty);
> @@ -673,7 +642,6 @@ long st_write(struct sk_buff *skb)
> return -EINVAL;
> }
>
> - pr_debug("%d to be written", skb->len);
> len = skb->len;
>
> /* st_ll to decide where to enqueue the skb */
> @@ -696,7 +664,6 @@ static int st_tty_open(struct tty_struct *tty)
> {
> int err = 0;
> struct st_data_s *st_gdata;
> - pr_info("%s ", __func__);
>
> st_kim_ref(&st_gdata, 0);
> st_gdata->tty = tty;
> @@ -716,7 +683,6 @@ static int st_tty_open(struct tty_struct *tty)
> * installation of N_TI_WL ldisc is complete
> */
> st_kim_complete(st_gdata->kim_data);
> - pr_debug("done %s", __func__);
> return err;
> }
>
> @@ -726,8 +692,6 @@ static void st_tty_close(struct tty_struct *tty)
> unsigned long flags = 0;
> struct st_data_s *st_gdata = tty->disc_data;
>
> - pr_info("%s ", __func__);
> -
> /* TODO:
> * if a protocol has been registered & line discipline
> * un-installed for some reason - what should be done ?
> @@ -762,7 +726,6 @@ static void st_tty_close(struct tty_struct *tty)
> st_gdata->rx_skb = NULL;
> spin_unlock_irqrestore(&st_gdata->lock, flags);
>
> - pr_debug("%s: done ", __func__);
> }
>
> static void st_tty_receive(struct tty_struct *tty, const unsigned char *data,
> @@ -778,7 +741,6 @@ static void st_tty_receive(struct tty_struct *tty, const unsigned char *data,
> * to KIM for validation
> */
> st_recv(tty->disc_data, data, count);
> - pr_debug("done %s", __func__);
> }
>
> /* wake-up function called in from the TTY layer
> @@ -787,7 +749,7 @@ static void st_tty_receive(struct tty_struct *tty, const unsigned char *data,
> static void st_tty_wakeup(struct tty_struct *tty)
> {
> struct st_data_s *st_gdata = tty->disc_data;
> - pr_debug("%s ", __func__);
> +
> /* don't do an wakeup for now */
> clear_bit(TTY_DO_WRITE_WAKEUP, &tty->flags);
>
> @@ -798,7 +760,6 @@ static void st_tty_wakeup(struct tty_struct *tty)
> static void st_tty_flush_buffer(struct tty_struct *tty)
> {
> struct st_data_s *st_gdata = tty->disc_data;
> - pr_debug("%s ", __func__);
>
> kfree_skb(st_gdata->tx_skb);
> st_gdata->tx_skb = NULL;
> @@ -826,18 +787,16 @@ int st_core_init(struct st_data_s **core_data)
>
> err = tty_register_ldisc(N_TI_WL, &st_ldisc_ops);
> if (err) {
> - pr_err("error registering %d line discipline %ld",
> - N_TI_WL, err);
> + pr_err("error registering %d line discipline", N_TI_WL);
> return err;
> }
> - pr_debug("registered n_shared line discipline");
>
> st_gdata = kzalloc(sizeof(struct st_data_s), GFP_KERNEL);
> if (!st_gdata) {
> - pr_err("memory allocation failed");
> + pr_err("%s: memory allocation failed", __func__);
> err = tty_unregister_ldisc(N_TI_WL);
> if (err)
> - pr_err("unable to un-register ldisc %ld", err);
> + pr_err("unable to un-register ldisc");
> err = -ENOMEM;
> return err;
> }
> @@ -853,7 +812,7 @@ int st_core_init(struct st_data_s **core_data)
>
> err = st_ll_init(st_gdata);
> if (err) {
> - pr_err("error during st_ll initialization(%ld)", err);
> + pr_err("error during st_ll initialization");
> kfree(st_gdata);
> err = tty_unregister_ldisc(N_TI_WL);
> if (err)
> @@ -870,7 +829,7 @@ void st_core_exit(struct st_data_s *st_gdata)
> /* internal module cleanup */
> err = st_ll_deinit(st_gdata);
> if (err)
> - pr_err("error during deinit of ST LL %ld", err);
> + pr_err("error during deinit of ST LL");
>
> if (st_gdata != NULL) {
> /* Free ST Tx Qs and skbs */
> @@ -881,7 +840,7 @@ void st_core_exit(struct st_data_s *st_gdata)
> /* TTY ldisc cleanup */
> err = tty_unregister_ldisc(N_TI_WL);
> if (err)
> - pr_err("unable to un-register ldisc %ld", err);
> + pr_err("unable to un-register ldisc");
> /* free the global data pointer */
> kfree(st_gdata);
> }
> diff --git a/drivers/misc/ti-st/st_kim.c b/drivers/misc/ti-st/st_kim.c
> index a7a861c..26df5c0 100644
> --- a/drivers/misc/ti-st/st_kim.c
> +++ b/drivers/misc/ti-st/st_kim.c
> @@ -20,7 +20,6 @@
> *
> */
>
> -#define pr_fmt(fmt) "(stk) :" fmt
> #include <linux/platform_device.h>
> #include <linux/jiffies.h>
> #include <linux/firmware.h>
> @@ -67,8 +66,7 @@ void validate_firmware_response(struct kim_data_s *kim_gdata)
> {
> struct sk_buff *skb = kim_gdata->rx_skb;
> if (unlikely(skb->data[5] != 0)) {
> - pr_err("no proper response during fw download");
> - pr_err("data6 %x", skb->data[5]);
> + dev_err(&kim_gdata->kim_pdev->dev, "No proper response during fw download");
> kfree_skb(skb);
> return; /* keep waiting for the proper response */
> }
> @@ -84,16 +82,14 @@ static inline int kim_check_data_len(struct kim_data_s *kim_gdata, int len)
> {
> register int room = skb_tailroom(kim_gdata->rx_skb);
>
> - pr_debug("len %d room %d", len, room);
> -
> if (!len) {
> validate_firmware_response(kim_gdata);
> } else if (len > room) {
> /* Received packet's payload length is larger.
> * We can't accommodate it in created skb.
> */
> - pr_err("Data length is too large len %d room %d", len,
> - room);
> + dev_err(&kim_gdata->kim_pdev->dev, "Data length is too large:"
> + "len - %d room - %d", len, room);
> kfree_skb(kim_gdata->rx_skb);
> } else {
> /* Packet header has non-zero payload length and
> @@ -126,11 +122,10 @@ void kim_int_recv(struct kim_data_s *kim_gdata,
> int len = 0, type = 0;
> unsigned char *plen;
>
> - pr_debug("%s", __func__);
> /* Decode received bytes here */
> ptr = data;
> if (unlikely(ptr == NULL)) {
> - pr_err(" received null from TTY ");
> + dev_err(&kim_gdata->kim_pdev->dev, "Received null from TTY");
> return;
> }
>
> @@ -149,7 +144,6 @@ void kim_int_recv(struct kim_data_s *kim_gdata,
> switch (kim_gdata->rx_state) {
> /* Waiting for complete packet ? */
> case ST_W4_DATA:
> - pr_debug("Complete pkt received");
> validate_firmware_response(kim_gdata);
> kim_gdata->rx_state = ST_W4_PACKET_TYPE;
> kim_gdata->rx_skb = NULL;
> @@ -158,11 +152,10 @@ void kim_int_recv(struct kim_data_s *kim_gdata,
> case ST_W4_HEADER:
> plen =
> (unsigned char *)&kim_gdata->rx_skb->data[1];
> - pr_debug("event hdr: plen 0x%02x\n", *plen);
> kim_check_data_len(kim_gdata, *plen);
> continue;
> - } /* end of switch */
> - } /* end of if rx_state */
> + }
> + }
> switch (*ptr) {
> /* Bluetooth event packet? */
> case 0x04:
> @@ -171,7 +164,6 @@ void kim_int_recv(struct kim_data_s *kim_gdata,
> type = *ptr;
> break;
> default:
> - pr_info("unknown packet");
> ptr++;
> count--;
> continue;
> @@ -181,7 +173,8 @@ void kim_int_recv(struct kim_data_s *kim_gdata,
> kim_gdata->rx_skb =
> alloc_skb(1024+8, GFP_ATOMIC);
> if (!kim_gdata->rx_skb) {
> - pr_err("can't allocate mem for new packet");
> + dev_err(&kim_gdata->kim_pdev->dev, "%s: Can't allocate mem for "
> + "new packet", __func__);
> kim_gdata->rx_state = ST_W4_PACKET_TYPE;
> kim_gdata->rx_count = 0;
> return;
> @@ -199,17 +192,15 @@ static long read_local_version(struct kim_data_s *kim_gdata, char *bts_scr_name)
> unsigned short version = 0, chip = 0, min_ver = 0, maj_ver = 0;
> const char read_ver_cmd[] = { 0x01, 0x01, 0x10, 0x00 };
>
> - pr_debug("%s", __func__);
> -
> INIT_COMPLETION(kim_gdata->kim_rcvd);
> - if (4 != st_int_write(kim_gdata->core_data, read_ver_cmd, 4)) {
> - pr_err("kim: couldn't write 4 bytes");
> + if (st_int_write(kim_gdata->core_data, read_ver_cmd, 4) != 4) {
> + dev_err(&kim_gdata->kim_pdev->dev, "Failed to write 4 bytes");
> return -EIO;
> }
>
> if (!wait_for_completion_timeout
> (&kim_gdata->kim_rcvd, msecs_to_jiffies(CMD_RESP_TIME))) {
> - pr_err(" waiting for ver info- timed out ");
> + dev_err(&kim_gdata->kim_pdev->dev, "Time out waiting for ver info");
> return -ETIMEDOUT;
> }
> INIT_COMPLETION(kim_gdata->kim_rcvd);
> @@ -232,7 +223,6 @@ static long read_local_version(struct kim_data_s *kim_gdata, char *bts_scr_name)
> kim_gdata->version.maj_ver = maj_ver;
> kim_gdata->version.min_ver = min_ver;
>
> - pr_info("%s", bts_scr_name);
> return 0;
> }
>
> @@ -245,14 +235,14 @@ void skip_change_remote_baud(unsigned char **ptr, long *len)
> ((struct bts_action *) cur_action)->size;
>
> if (((struct bts_action *) nxt_action)->type != ACTION_WAIT_EVENT) {
> - pr_err("invalid action after change remote baud command");
> + pr_debug("Invalid action after change remote baud command");
> } else {
> *ptr = *ptr + sizeof(struct bts_action) +
> ((struct bts_action *)cur_action)->size;
> *len = *len - (sizeof(struct bts_action) +
> ((struct bts_action *)cur_action)->size);
> /* warn user on not commenting these in firmware */
> - pr_warn("skipping the wait event of change remote baud");
> + pr_debug("Skipping the wait event of change remote baud");
> }
> }
>
> @@ -274,7 +264,7 @@ static long download_firmware(struct kim_data_s *kim_gdata)
>
> err = read_local_version(kim_gdata, bts_scr_name);
> if (err != 0) {
> - pr_err("kim: failed to read local ver");
> + dev_err(&kim_gdata->kim_pdev->dev, "Failed to read local ver");
> return err;
> }
> err =
> @@ -282,7 +272,7 @@ static long download_firmware(struct kim_data_s *kim_gdata)
> &kim_gdata->kim_pdev->dev);
> if (unlikely((err != 0) || (kim_gdata->fw_entry->data == NULL) ||
> (kim_gdata->fw_entry->size == 0))) {
> - pr_err(" request_firmware failed(errno %ld) for %s", err,
> + dev_err(&kim_gdata->kim_pdev->dev, "Firmware download failed for %s",
> bts_scr_name);
> return -EINVAL;
> }
> @@ -295,21 +285,14 @@ static long download_firmware(struct kim_data_s *kim_gdata)
> len -= sizeof(struct bts_header);
>
> while (len > 0 && ptr) {
> - pr_debug(" action size %d, type %d ",
> - ((struct bts_action *)ptr)->size,
> - ((struct bts_action *)ptr)->type);
> -
> switch (((struct bts_action *)ptr)->type) {
> case ACTION_SEND_COMMAND: /* action send */
> - pr_debug("S");
> action_ptr = &(((struct bts_action *)ptr)->data[0]);
> if (unlikely
> (((struct hci_command *)action_ptr)->opcode ==
> 0xFF36)) {
> /* ignore remote change
> * baud rate HCI VS command */
> - pr_warn("change remote baud"
> - " rate command in firmware");
> skip_change_remote_baud(&ptr, &len);
> break;
> }
> @@ -323,7 +306,7 @@ static long download_firmware(struct kim_data_s *kim_gdata)
> wr_room_space =
> st_get_uart_wr_room(kim_gdata->core_data);
> if (wr_room_space < 0) {
> - pr_err("Unable to get free "
> + dev_err(&kim_gdata->kim_pdev->dev, "Unable to get free "
> "space info from uart tx buffer");
> release_firmware(kim_gdata->fw_entry);
> return wr_room_space;
> @@ -334,8 +317,8 @@ static long download_firmware(struct kim_data_s *kim_gdata)
>
> /* Timeout happened ? */
> if (time_after_eq(jiffies, timeout)) {
> - pr_err("Timeout while waiting for free "
> - "free space in uart tx buffer");
> + dev_err(&kim_gdata->kim_pdev->dev, "Timeout while waiting"
> + "for free free space in uart tx buffer");
> release_firmware(kim_gdata->fw_entry);
> return -ETIMEDOUT;
> }
> @@ -361,19 +344,19 @@ static long download_firmware(struct kim_data_s *kim_gdata)
> * and requested command write size
> */
> if (err != cmd_size) {
> - pr_err("Number of bytes written to uart "
> - "tx buffer are not matching with "
> + dev_err(&kim_gdata->kim_pdev->dev, "Number of bytes written "
> + "to uart tx buffer are not matching with "
> "requested cmd write size");
> release_firmware(kim_gdata->fw_entry);
> return -EIO;
> }
> break;
> case ACTION_WAIT_EVENT: /* wait */
> - pr_debug("W");
> if (!wait_for_completion_timeout
> (&kim_gdata->kim_rcvd,
> msecs_to_jiffies(CMD_RESP_TIME))) {
> - pr_err("response timeout during fw download ");
> + dev_err(&kim_gdata->kim_pdev->dev, "Response timeout during "
> + "fw download");
> /* timed out */
> release_firmware(kim_gdata->fw_entry);
> return -ETIMEDOUT;
> @@ -381,7 +364,6 @@ static long download_firmware(struct kim_data_s *kim_gdata)
> INIT_COMPLETION(kim_gdata->kim_rcvd);
> break;
> case ACTION_DELAY: /* sleep */
> - pr_info("sleep command in scr");
> action_ptr = &(((struct bts_action *)ptr)->data[0]);
> mdelay(((struct bts_action_delay *)action_ptr)->msec);
> break;
> @@ -393,6 +375,8 @@ static long download_firmware(struct kim_data_s *kim_gdata)
> ptr + sizeof(struct bts_action) +
> ((struct bts_action *)ptr)->size;
> }
> +
> + dev_info(&kim_gdata->kim_pdev->dev, "Loaded %s firmware", bts_scr_name);
> /* fw download complete */
> release_firmware(kim_gdata->fw_entry);
> return 0;
> @@ -446,7 +430,6 @@ long st_kim_start(void *kim_data)
> struct ti_st_plat_data *pdata;
> struct kim_data_s *kim_gdata = (struct kim_data_s *)kim_data;
>
> - pr_info(" %s", __func__);
> pdata = kim_gdata->kim_pdev->dev.platform_data;
>
> do {
> @@ -463,26 +446,24 @@ long st_kim_start(void *kim_data)
> INIT_COMPLETION(kim_gdata->ldisc_installed);
> /* send notification to UIM */
> kim_gdata->ldisc_install = 1;
> - pr_info("ldisc_install = 1");
> - sysfs_notify(&kim_gdata->kim_pdev->dev.kobj,
> - NULL, "install");
> + sysfs_notify(&kim_gdata->kim_pdev->dev.kobj, NULL, "install");
> /* wait for ldisc to be installed */
> err = wait_for_completion_timeout(&kim_gdata->ldisc_installed,
> msecs_to_jiffies(LDISC_TIME));
> if (!err) {
> /* ldisc installation timeout,
> * flush uart, power cycle BT_EN */
> - pr_err("ldisc installation timeout");
> + dev_err(&kim_gdata->kim_pdev->dev, "Ldisc installation timeout");
> err = st_kim_stop(kim_gdata);
> continue;
> } else {
> /* ldisc installed now */
> - pr_info("line discipline installed");
> + dev_info(&kim_gdata->kim_pdev->dev, "Line discipline installed");
> err = download_firmware(kim_gdata);
> if (err != 0) {
> /* ldisc installed but fw download failed,
> * flush uart & power cycle BT_EN */
> - pr_err("download firmware failed");
> + dev_err(&kim_gdata->kim_pdev->dev, "Download firmware failed");
> err = st_kim_stop(kim_gdata);
> continue;
> } else { /* on success don't retry */
> @@ -521,7 +502,6 @@ long st_kim_stop(void *kim_data)
> }
>
> /* send uninstall notification to UIM */
> - pr_info("ldisc_install = 0");
> kim_gdata->ldisc_install = 0;
> sysfs_notify(&kim_gdata->kim_pdev->dev.kobj, NULL, "install");
>
> @@ -529,7 +509,7 @@ long st_kim_stop(void *kim_data)
> err = wait_for_completion_timeout(&kim_gdata->ldisc_installed,
> msecs_to_jiffies(LDISC_TIME));
> if (!err) { /* timeout */
> - pr_err(" timed out waiting for ldisc to be un-installed");
> + dev_err(&kim_gdata->kim_pdev->dev, "Timed out waiting for ldisc to be un-installed");
> return -ETIMEDOUT;
> }
>
> @@ -718,14 +698,14 @@ static int kim_probe(struct platform_device *pdev)
>
> kim_gdata = kzalloc(sizeof(struct kim_data_s), GFP_ATOMIC);
> if (!kim_gdata) {
> - pr_err("no mem to allocate");
> + dev_err(&pdev->dev, "%s: No mem to allocate", __func__);
> return -ENOMEM;
> }
> dev_set_drvdata(&pdev->dev, kim_gdata);
>
> status = st_core_init(&kim_gdata->core_data);
> if (status != 0) {
> - pr_err(" ST core init failed");
> + dev_err(&pdev->dev, "ST core init failed");
> return -EIO;
> }
> /* refer to itself */
> @@ -735,14 +715,14 @@ static int kim_probe(struct platform_device *pdev)
> kim_gdata->nshutdown = pdata->nshutdown_gpio;
> status = gpio_request(kim_gdata->nshutdown, "kim");
> if (unlikely(status)) {
> - pr_err(" gpio %ld request failed ", kim_gdata->nshutdown);
> + dev_err(&pdev->dev, "Gpio %ld request failed ", kim_gdata->nshutdown);
> return status;
> }
>
> /* Configure nShutdown GPIO as output=0 */
> status = gpio_direction_output(kim_gdata->nshutdown, 0);
> if (unlikely(status)) {
> - pr_err(" unable to configure gpio %ld", kim_gdata->nshutdown);
> + dev_err(&pdev->dev, "Unable to configure gpio %ld", kim_gdata->nshutdown);
> return status;
> }
> /* get reference of pdev for request_firmware
> @@ -753,7 +733,7 @@ static int kim_probe(struct platform_device *pdev)
>
> status = sysfs_create_group(&pdev->dev.kobj, &uim_attr_grp);
> if (status) {
> - pr_err("failed to create sysfs entries");
> + dev_err(&pdev->dev, "Failed to create sysfs entries");
> return status;
> }
>
> @@ -761,11 +741,11 @@ static int kim_probe(struct platform_device *pdev)
> strncpy(kim_gdata->dev_name, pdata->dev_name, UART_DEV_NAME_LEN);
> kim_gdata->flow_cntrl = pdata->flow_cntrl;
> kim_gdata->baud_rate = pdata->baud_rate;
> - pr_info("sysfs entries created\n");
> + dev_info(&pdev->dev, "sysfs entries created\n");
>
> kim_debugfs_dir = debugfs_create_dir("ti-st", NULL);
> if (IS_ERR(kim_debugfs_dir)) {
> - pr_err(" debugfs entries creation failed ");
> + dev_err(&pdev->dev, "Failed to create debugfs entries");
> kim_debugfs_dir = NULL;
> return -EIO;
> }
> @@ -774,7 +754,7 @@ static int kim_probe(struct platform_device *pdev)
> kim_gdata, &version_debugfs_fops);
> debugfs_create_file("protocols", S_IRUGO, kim_debugfs_dir,
> kim_gdata, &list_debugfs_fops);
> - pr_info(" debugfs entries created ");
> + dev_info(&pdev->dev, "debugfs entries created");
> return 0;
> }
>
> @@ -790,11 +770,11 @@ static int kim_remove(struct platform_device *pdev)
> * nShutdown gpio from the system
> */
> gpio_free(pdata->nshutdown_gpio);
> - pr_info("nshutdown GPIO Freed");
> + dev_info(&pdev->dev, "nshutdown GPIO Freed");
>
> debugfs_remove_recursive(kim_debugfs_dir);
> sysfs_remove_group(&pdev->dev.kobj, &uim_attr_grp);
> - pr_info("sysfs entries removed");
> + dev_info(&pdev->dev, "sysfs entries removed");
>
> kim_gdata->kim_pdev = NULL;
> st_core_exit(kim_gdata->core_data);
> diff --git a/drivers/misc/ti-st/st_ll.c b/drivers/misc/ti-st/st_ll.c
> index 1ff460a..0f502d4 100644
> --- a/drivers/misc/ti-st/st_ll.c
> +++ b/drivers/misc/ti-st/st_ll.c
> @@ -19,7 +19,6 @@
> *
> */
>
> -#define pr_fmt(fmt) "(stll) :" fmt
> #include <linux/skbuff.h>
> #include <linux/module.h>
> #include <linux/platform_device.h>
> @@ -30,8 +29,6 @@
> static void send_ll_cmd(struct st_data_s *st_data,
> unsigned char cmd)
> {
> -
> - pr_debug("%s: writing %x", __func__, cmd);
> st_int_write(st_data, &cmd, 1);
> return;
> }
> @@ -41,7 +38,6 @@ static void ll_device_want_to_sleep(struct st_data_s *st_data)
> struct kim_data_s *kim_data;
> struct ti_st_plat_data *pdata;
>
> - pr_debug("%s", __func__);
> /* sanity check */
> if (st_data->ll_state != ST_LL_AWAKE)
> pr_err("ERR hcill: ST_LL_GO_TO_SLEEP_IND"
> @@ -70,15 +66,15 @@ static void ll_device_want_to_wakeup(struct st_data_s *st_data)
> break;
> case ST_LL_ASLEEP_TO_AWAKE:
> /* duplicate wake_ind */
> - pr_err("duplicate wake_ind while waiting for Wake ack");
> + pr_debug("duplicate wake_ind while waiting for Wake ack");
> break;
> case ST_LL_AWAKE:
> /* duplicate wake_ind */
> - pr_err("duplicate wake_ind already AWAKE");
> + pr_debug("duplicate wake_ind already AWAKE");
> break;
> case ST_LL_AWAKE_TO_ASLEEP:
> /* duplicate wake_ind */
> - pr_err("duplicate wake_ind");
> + pr_debug("duplicate wake_ind");
> break;
> }
> /* update state */
> @@ -116,14 +112,13 @@ void st_ll_wakeup(struct st_data_s *ll)
> ll->ll_state = ST_LL_ASLEEP_TO_AWAKE;
> } else {
> /* don't send the duplicate wake_indication */
> - pr_err(" Chip already AWAKE ");
> + pr_debug("Chip already AWAKE");
> }
> }
>
> /* called when ST Core wants the state */
> unsigned long st_ll_getstate(struct st_data_s *ll)
> {
> - pr_debug(" returning state %ld", ll->ll_state);
> return ll->ll_state;
> }
>
> @@ -137,7 +132,7 @@ unsigned long st_ll_sleep_state(struct st_data_s *st_data,
> ll_device_want_to_sleep(st_data);
> break;
> case LL_SLEEP_ACK: /* sleep ack */
> - pr_err("sleep ack rcvd: host shouldn't");
> + pr_debug("sleep ack rcvd: host shouldn't");
> break;
> case LL_WAKE_UP_IND: /* wake ind */
> pr_debug("wake indication recvd");
> @@ -148,7 +143,7 @@ unsigned long st_ll_sleep_state(struct st_data_s *st_data,
> st_data->ll_state = ST_LL_AWAKE;
> break;
> default:
> - pr_err(" unknown input/state ");
> + pr_err("unknown input/state");
> return -EINVAL;
> }
> return 0;

--
Ing. Mircea Gherzan