2007-09-23 15:32:40

by Simon Arlott

[permalink] [raw]
Subject: [PATCH 1/2] cxacru: Use appropriate logging for errors

When an error occurs, existing logging uses dbg() so the cause of a
problem is hard to determine. Error conditions shouldn't only be
properly reported with debugging enabled.

A side effect of this change is that when an uninitialised device
is started, a log message similar to the following is sent:
cxacru 5-2:1.0: receive of cm 0x90 failed (-104)
This is normal - the device did not respond so firmware will be
loaded.

Signed-Off-By: Simon Arlott <[email protected]>
---
This could be added to 2.6.23 since it only makes error logging
more verbose.

drivers/usb/atm/cxacru.c | 29 ++++++++++++++++++-----------
1 files changed, 18 insertions(+), 11 deletions(-)

diff --git a/drivers/usb/atm/cxacru.c b/drivers/usb/atm/cxacru.c
index a73e714..8d8a107 100644
--- a/drivers/usb/atm/cxacru.c
+++ b/drivers/usb/atm/cxacru.c
@@ -482,7 +482,8 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
int rbuflen = ((rsize - 1) / stride + 1) * CMD_PACKET_SIZE;

if (wbuflen > PAGE_SIZE || rbuflen > PAGE_SIZE) {
- dbg("too big transfer requested");
+ usb_err(instance->usbatm, "requested transfer size too large (%d, %d)\n",
+ wbuflen, rbuflen);
ret = -ENOMEM;
goto fail;
}
@@ -493,7 +494,8 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
init_completion(&instance->rcv_done);
ret = usb_submit_urb(instance->rcv_urb, GFP_KERNEL);
if (ret < 0) {
- dbg("submitting read urb for cm %#x failed", cm);
+ usb_err(instance->usbatm, "submit of read urb for cm %#x failed (%d)\n",
+ cm, ret);
ret = ret;
goto fail;
}
@@ -510,27 +512,28 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
init_completion(&instance->snd_done);
ret = usb_submit_urb(instance->snd_urb, GFP_KERNEL);
if (ret < 0) {
- dbg("submitting write urb for cm %#x failed", cm);
+ usb_err(instance->usbatm, "submit of write urb for cm %#x failed (%d)\n",
+ cm, ret);
ret = ret;
goto fail;
}

ret = cxacru_start_wait_urb(instance->snd_urb, &instance->snd_done, NULL);
if (ret < 0) {
- dbg("sending cm %#x failed", cm);
+ usb_err(instance->usbatm, "send of cm %#x failed (%d)\n", cm, ret);
ret = ret;
goto fail;
}

ret = cxacru_start_wait_urb(instance->rcv_urb, &instance->rcv_done, &actlen);
if (ret < 0) {
- dbg("receiving cm %#x failed", cm);
+ usb_err(instance->usbatm, "receive of cm %#x failed (%d)\n", cm, ret);
ret = ret;
goto fail;
}
if (actlen % CMD_PACKET_SIZE || !actlen) {
- dbg("response is not a positive multiple of %d: %#x",
- CMD_PACKET_SIZE, actlen);
+ usb_err(instance->usbatm, "invalid response length to cm %#x: %d\n",
+ cm, actlen);
ret = -EIO;
goto fail;
}
@@ -538,12 +541,14 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
/* check the return status and copy the data to the output buffer, if needed */
for (offb = offd = 0; offd < rsize && offb < actlen; offb += CMD_PACKET_SIZE) {
if (rbuf[offb] != cm) {
- dbg("wrong cm %#x in response", rbuf[offb]);
+ usb_err(instance->usbatm, "wrong cm %#x in response to cm %#x\n",
+ rbuf[offb], cm);
ret = -EIO;
goto fail;
}
if (rbuf[offb + 1] != CM_STATUS_SUCCESS) {
- dbg("response failed: %#x", rbuf[offb + 1]);
+ usb_err(instance->usbatm, "response to cm %#x failed: %#x\n",
+ cm, rbuf[offb + 1]);
ret = -EIO;
goto fail;
}
@@ -582,14 +587,16 @@ static int cxacru_cm_get_array(struct cxacru_data *instance, enum cxacru_cm_requ
for (offb = 0; offb < len; ) {
int l = le32_to_cpu(buf[offb++]);
if (l > stride || l > (len - offb) / 2) {
- dbg("wrong data length %#x in response", l);
+ usb_err(instance->usbatm, "invalid data length from cm %#x: %d\n",
+ cm, l);
ret = -EIO;
goto cleanup;
}
while (l--) {
offd = le32_to_cpu(buf[offb++]);
if (offd >= size) {
- dbg("wrong index %#x in response", offd);
+ usb_err(instance->usbatm, "wrong index #%x in response to cm #%x\n",
+ offd, cm);
ret = -EIO;
goto cleanup;
}
--
1.5.0.1

--
Simon Arlott


2007-09-23 15:35:03

by Simon Arlott

[permalink] [raw]
Subject: [PATCH 2/3] cxacru: Reduce initialisation delay

Since card status updates appear to only occur every second, a delay
of 1000ms on startup may not be sufficient - change to 1500ms.

The long delay of 4000ms is likely to be related to the time required
for the ADSL line to come up - the driver should not need to do this.

Overall delay when loading firmware will change from 5000ms to 1500ms.

Signed-Off-By: Simon Arlott <[email protected]>
---
drivers/usb/atm/cxacru.c | 9 +++++----
1 files changed, 5 insertions(+), 4 deletions(-)

diff --git a/drivers/usb/atm/cxacru.c b/drivers/usb/atm/cxacru.c
index 8d8a107..35308a8 100644
--- a/drivers/usb/atm/cxacru.c
+++ b/drivers/usb/atm/cxacru.c
@@ -931,9 +931,10 @@ static void cxacru_upload_firmware(struct cxacru_data *instance,
usb_err(usbatm, "Passing control to firmware failed: %d\n", ret);
return;
}
+ usb_info(usbatm, "started firmware\n");

/* Delay to allow firmware to start up. */
- msleep_interruptible(1000);
+ msleep(1500);

usb_clear_halt(usb_dev, usb_sndbulkpipe(usb_dev, CXACRU_EP_CMD));
usb_clear_halt(usb_dev, usb_rcvbulkpipe(usb_dev, CXACRU_EP_CMD));
@@ -947,7 +948,7 @@ static void cxacru_upload_firmware(struct cxacru_data *instance,
}

/* Load config data (le32), doing one packet at a time */
- if (cf)
+ if (cf) {
for (off = 0; off < cf->size / 4; ) {
u32 buf[CMD_PACKET_SIZE / 4 - 1];
int i, len = min_t(int, cf->size / 4 - off, CMD_PACKET_SIZE / 4 / 2 - 1);
@@ -963,8 +964,8 @@ static void cxacru_upload_firmware(struct cxacru_data *instance,
return;
}
}
-
- msleep_interruptible(4000);
+ usb_info(usbatm, "loaded config data\n");
+ }
}

static int cxacru_find_firmware(struct cxacru_data *instance,
--
1.5.0.1

--
Simon Arlott

2007-09-23 15:36:19

by Simon Arlott

[permalink] [raw]
Subject: Re: [PATCH 3/3] cxacru: Cleanup code by removing "ret = ret;" assignments

Cleanup code by removing "ret = ret;" assignments.

Signed-Off-By: Simon Arlott <[email protected]>
---
drivers/usb/atm/cxacru.c | 4 ----
1 files changed, 0 insertions(+), 4 deletions(-)

diff --git a/drivers/usb/atm/cxacru.c b/drivers/usb/atm/cxacru.c
index 35308a8..bb3169c 100644
--- a/drivers/usb/atm/cxacru.c
+++ b/drivers/usb/atm/cxacru.c
@@ -496,7 +496,6 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
if (ret < 0) {
usb_err(instance->usbatm, "submit of read urb for cm %#x failed (%d)\n",
cm, ret);
- ret = ret;
goto fail;
}

@@ -514,21 +513,18 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
if (ret < 0) {
usb_err(instance->usbatm, "submit of write urb for cm %#x failed (%d)\n",
cm, ret);
- ret = ret;
goto fail;
}

ret = cxacru_start_wait_urb(instance->snd_urb, &instance->snd_done, NULL);
if (ret < 0) {
usb_err(instance->usbatm, "send of cm %#x failed (%d)\n", cm, ret);
- ret = ret;
goto fail;
}

ret = cxacru_start_wait_urb(instance->rcv_urb, &instance->rcv_done, &actlen);
if (ret < 0) {
usb_err(instance->usbatm, "receive of cm %#x failed (%d)\n", cm, ret);
- ret = ret;
goto fail;
}
if (actlen % CMD_PACKET_SIZE || !actlen) {
--
1.5.0.1

--
Simon Arlott

2007-09-23 16:17:50

by Duncan Sands

[permalink] [raw]
Subject: Re: [PATCH 1/2] cxacru: Use appropriate logging for errors

Hi Simon, don't these error messages (except the first) risk spamming
the log if something goes wrong (like the modem being unplugged)? How
about rate-limiting them, like usbatm does?

Ciao,

Duncan.

2007-09-23 16:20:43

by Duncan Sands

[permalink] [raw]
Subject: Re: [PATCH 3/3] cxacru: Cleanup code by removing "ret = ret;" assignments

On Sunday 23 September 2007 17:36:08 Simon Arlott wrote:
> Cleanup code by removing "ret = ret;" assignments.
>
> Signed-Off-By: Simon Arlott <[email protected]>

Acked-by: Duncan Sands <[email protected]>

2007-09-23 16:23:29

by Duncan Sands

[permalink] [raw]
Subject: Re: [PATCH 2/3] cxacru: Reduce initialisation delay

Hi Simon,

> + usb_info(usbatm, "started firmware\n");
...
> + usb_info(usbatm, "loaded config data\n");

maybe these should be debug messages. When are they useful?

Ciao,

Duncan.

2007-09-23 18:33:17

by Simon Arlott

[permalink] [raw]
Subject: Re: [PATCH 2/3] cxacru: Reduce initialisation delay

On 23/09/07 17:23, Duncan Sands wrote:
> Hi Simon,
>
>> + usb_info(usbatm, "started firmware\n");
> ...
>> + usb_info(usbatm, "loaded config data\n");
>
> maybe these should be debug messages. When are they useful?

They are probably only useful as debug messages - although it
may be desirable to know when the configuration has been set.



Also... it doesn't make sense to load the configuration only
in heavy_init - if the configuration is changed then there's
no way in the module to resend it without powering the device
down and up. Some sysfs parameters to change configuration
could be useful... except there's no information as to what
these settings are.

--
Simon Arlott

2007-09-23 18:36:18

by Simon Arlott

[permalink] [raw]
Subject: Re: [PATCH 3/3] cxacru: Cleanup code by removing "ret = ret;" assignments

On 23/09/07 17:20, Duncan Sands wrote:
> On Sunday 23 September 2007 17:36:08 Simon Arlott wrote:
>> Cleanup code by removing "ret = ret;" assignments.
>>
>> Signed-Off-By: Simon Arlott <[email protected]>
>
> Acked-by: Duncan Sands <[email protected]>

Nacked-by: Simon Arlott <[email protected]>

I'm only going to create a merge conflict with myself with this :|
It'll be included with 1/3 shortly.

--
Simon Arlott

2007-09-23 18:44:16

by Simon Arlott

[permalink] [raw]
Subject: [PATCH 1/2 (v2)] cxacru: Use appropriate logging for errors

When an error occurs, existing logging uses dbg() so the cause of a
problem is hard to determine. Error conditions shouldn't only be
properly reported with debugging enabled.

A side effect of this change is that when an uninitialised device
is started, a log message similar to the following is sent:
cxacru 5-2:1.0: receive of cm 0x90 failed (-104)
This is normal - the device did not respond so firmware will be
loaded.

Signed-Off-By: Simon Arlott <[email protected]>
---
On 23/09/07 17:17, Duncan Sands wrote:
> Hi Simon, don't these error messages (except the first) risk spamming
> the log if something goes wrong (like the modem being unplugged)? How
> about rate-limiting them, like usbatm does?
>
> Ciao,
>
> Duncan.

Ok.

drivers/usb/atm/cxacru.c | 43 ++++++++++++++++++++++++++++---------------
1 files changed, 28 insertions(+), 15 deletions(-)

diff --git a/drivers/usb/atm/cxacru.c b/drivers/usb/atm/cxacru.c
index 1e5ee88..50249a5 100644
--- a/drivers/usb/atm/cxacru.c
+++ b/drivers/usb/atm/cxacru.c
@@ -482,7 +482,9 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
int rbuflen = ((rsize - 1) / stride + 1) * CMD_PACKET_SIZE;

if (wbuflen > PAGE_SIZE || rbuflen > PAGE_SIZE) {
- dbg("too big transfer requested");
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "requested transfer size too large (%d, %d)\n",
+ wbuflen, rbuflen);
ret = -ENOMEM;
goto fail;
}
@@ -493,8 +495,9 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
init_completion(&instance->rcv_done);
ret = usb_submit_urb(instance->rcv_urb, GFP_KERNEL);
if (ret < 0) {
- dbg("submitting read urb for cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "submit of read urb for cm %#x failed (%d)\n",
+ cm, ret);
goto fail;
}

@@ -510,27 +513,29 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
init_completion(&instance->snd_done);
ret = usb_submit_urb(instance->snd_urb, GFP_KERNEL);
if (ret < 0) {
- dbg("submitting write urb for cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "submit of write urb for cm %#x failed (%d)\n",
+ cm, ret);
goto fail;
}

ret = cxacru_start_wait_urb(instance->snd_urb, &instance->snd_done, NULL);
if (ret < 0) {
- dbg("sending cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "send of cm %#x failed (%d)\n", cm, ret);
goto fail;
}

ret = cxacru_start_wait_urb(instance->rcv_urb, &instance->rcv_done, &actlen);
if (ret < 0) {
- dbg("receiving cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "receive of cm %#x failed (%d)\n", cm, ret);
goto fail;
}
if (actlen % CMD_PACKET_SIZE || !actlen) {
- dbg("response is not a positive multiple of %d: %#x",
- CMD_PACKET_SIZE, actlen);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "invalid response length to cm %#x: %d\n",
+ cm, actlen);
ret = -EIO;
goto fail;
}
@@ -538,12 +543,16 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
/* check the return status and copy the data to the output buffer, if needed */
for (offb = offd = 0; offd < rsize && offb < actlen; offb += CMD_PACKET_SIZE) {
if (rbuf[offb] != cm) {
- dbg("wrong cm %#x in response", rbuf[offb]);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "wrong cm %#x in response to cm %#x\n",
+ rbuf[offb], cm);
ret = -EIO;
goto fail;
}
if (rbuf[offb + 1] != CM_STATUS_SUCCESS) {
- dbg("response failed: %#x", rbuf[offb + 1]);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "response to cm %#x failed: %#x\n",
+ cm, rbuf[offb + 1]);
ret = -EIO;
goto fail;
}
@@ -582,14 +591,18 @@ static int cxacru_cm_get_array(struct cxacru_data *instance, enum cxacru_cm_requ
for (offb = 0; offb < len; ) {
int l = le32_to_cpu(buf[offb++]);
if (l > stride || l > (len - offb) / 2) {
- dbg("wrong data length %#x in response", l);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "invalid data length from cm %#x: %d\n",
+ cm, l);
ret = -EIO;
goto cleanup;
}
while (l--) {
offd = le32_to_cpu(buf[offb++]);
if (offd >= size) {
- dbg("wrong index %#x in response", offd);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "wrong index #%x in response to cm #%x\n",
+ offd, cm);
ret = -EIO;
goto cleanup;
}
--
1.5.0.1

--
Simon Arlott

2007-09-23 19:26:34

by Duncan Sands

[permalink] [raw]
Subject: Re: [PATCH 1/2 (v2)] cxacru: Use appropriate logging for errors

> - dbg("too big transfer requested");
> + if (printk_ratelimit())
> + usb_err(instance->usbatm, "requested transfer size too large (%d, %d)\n",
> + wbuflen, rbuflen);

etc

Acked-by: Duncan Sands <[email protected]>

2007-09-24 18:29:34

by Greg KH

[permalink] [raw]
Subject: Re: [PATCH 3/3] cxacru: Cleanup code by removing "ret = ret;" assignments

On Sun, Sep 23, 2007 at 07:36:05PM +0100, Simon Arlott wrote:
> On 23/09/07 17:20, Duncan Sands wrote:
> > On Sunday 23 September 2007 17:36:08 Simon Arlott wrote:
> >> Cleanup code by removing "ret = ret;" assignments.
> >>
> >> Signed-Off-By: Simon Arlott <[email protected]>
> >
> > Acked-by: Duncan Sands <[email protected]>
>
> Nacked-by: Simon Arlott <[email protected]>
>
> I'm only going to create a merge conflict with myself with this :|
> It'll be included with 1/3 shortly.

Ok, I'm totally confused :)

Can you resend the patches you want to have included here, that are
acked by both you and Duncan?

thanks,

greg k-h

2007-09-25 19:20:28

by Simon Arlott

[permalink] [raw]
Subject: [PATCH] cxacru: Use appropriate logging for errors

When an error occurs, existing logging uses dbg() so the cause of a
problem is hard to determine. Error conditions shouldn't only be
properly reported with debugging enabled.

A side effect of this change is that when an uninitialised device
is started, a log message similar to the following is sent:
cxacru 5-2:1.0: receive of cm 0x90 failed (-104)
This is normal - the device did not respond so firmware will be
loaded.

Signed-off-by: Simon Arlott <[email protected]>
Acked-by: Duncan Sands <[email protected]>
---
On 24/09/07 19:32, Greg KH wrote:
> On Sun, Sep 23, 2007 at 07:36:05PM +0100, Simon Arlott wrote:
>> I'm only going to create a merge conflict with myself with this :|
>> It'll be included with 1/3 shortly.
>
> Ok, I'm totally confused :)
>
> Can you resend the patches you want to have included here, that are
> acked by both you and Duncan?
>
> thanks,
>
> greg k-h

drivers/usb/atm/cxacru.c | 43 ++++++++++++++++++++++++++++---------------
1 files changed, 28 insertions(+), 15 deletions(-)

diff --git a/drivers/usb/atm/cxacru.c b/drivers/usb/atm/cxacru.c
index 1e5ee88..50249a5 100644
--- a/drivers/usb/atm/cxacru.c
+++ b/drivers/usb/atm/cxacru.c
@@ -482,7 +482,9 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
int rbuflen = ((rsize - 1) / stride + 1) * CMD_PACKET_SIZE;

if (wbuflen > PAGE_SIZE || rbuflen > PAGE_SIZE) {
- dbg("too big transfer requested");
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "requested transfer size too large (%d, %d)\n",
+ wbuflen, rbuflen);
ret = -ENOMEM;
goto fail;
}
@@ -493,8 +495,9 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
init_completion(&instance->rcv_done);
ret = usb_submit_urb(instance->rcv_urb, GFP_KERNEL);
if (ret < 0) {
- dbg("submitting read urb for cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "submit of read urb for cm %#x failed (%d)\n",
+ cm, ret);
goto fail;
}

@@ -510,27 +513,29 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
init_completion(&instance->snd_done);
ret = usb_submit_urb(instance->snd_urb, GFP_KERNEL);
if (ret < 0) {
- dbg("submitting write urb for cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "submit of write urb for cm %#x failed (%d)\n",
+ cm, ret);
goto fail;
}

ret = cxacru_start_wait_urb(instance->snd_urb, &instance->snd_done, NULL);
if (ret < 0) {
- dbg("sending cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "send of cm %#x failed (%d)\n", cm, ret);
goto fail;
}

ret = cxacru_start_wait_urb(instance->rcv_urb, &instance->rcv_done, &actlen);
if (ret < 0) {
- dbg("receiving cm %#x failed", cm);
- ret = ret;
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "receive of cm %#x failed (%d)\n", cm, ret);
goto fail;
}
if (actlen % CMD_PACKET_SIZE || !actlen) {
- dbg("response is not a positive multiple of %d: %#x",
- CMD_PACKET_SIZE, actlen);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "invalid response length to cm %#x: %d\n",
+ cm, actlen);
ret = -EIO;
goto fail;
}
@@ -538,12 +543,16 @@ static int cxacru_cm(struct cxacru_data *instance, enum cxacru_cm_request cm,
/* check the return status and copy the data to the output buffer, if needed */
for (offb = offd = 0; offd < rsize && offb < actlen; offb += CMD_PACKET_SIZE) {
if (rbuf[offb] != cm) {
- dbg("wrong cm %#x in response", rbuf[offb]);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "wrong cm %#x in response to cm %#x\n",
+ rbuf[offb], cm);
ret = -EIO;
goto fail;
}
if (rbuf[offb + 1] != CM_STATUS_SUCCESS) {
- dbg("response failed: %#x", rbuf[offb + 1]);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "response to cm %#x failed: %#x\n",
+ cm, rbuf[offb + 1]);
ret = -EIO;
goto fail;
}
@@ -582,14 +591,18 @@ static int cxacru_cm_get_array(struct cxacru_data *instance, enum cxacru_cm_requ
for (offb = 0; offb < len; ) {
int l = le32_to_cpu(buf[offb++]);
if (l > stride || l > (len - offb) / 2) {
- dbg("wrong data length %#x in response", l);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "invalid data length from cm %#x: %d\n",
+ cm, l);
ret = -EIO;
goto cleanup;
}
while (l--) {
offd = le32_to_cpu(buf[offb++]);
if (offd >= size) {
- dbg("wrong index %#x in response", offd);
+ if (printk_ratelimit())
+ usb_err(instance->usbatm, "wrong index #%x in response to cm #%x\n",
+ offd, cm);
ret = -EIO;
goto cleanup;
}
--
1.5.0.1

--
Simon Arlott