Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-27 Thread Hannes Reinecke

On 08/08/2014 03:07 PM, Douglas Gilbert wrote:

On 14-08-08 01:50 PM, Yoshihiro YUNOMAE wrote:

Hi All,

This patch set introduces new traceevents in order to output
continuous error
messages. Current SCSI printk messages in upstream kernel can be
divided by and
mixed with other messages. Even if each error message has its
device id,
sometimes we can easily be lost in mixed logs because the
message's device id
is separated from it's body. To avoid it, I'd like to use
traceevents to
store error messages into the ftrace or perf buuffer, because
traceevents
are atomically commited to the buffer.

In this patch set, all printk messages are removed based on a local
discussion with Hannes, but I think printk messages should be kept
because all
users don't enable traceevents and rsyslog can store as files.

However, if printk of logging branch is kept, the messages are
duplicate and
it can induce stack overflow by using local buffer(*1).

  (*1) https://lkml.org/lkml/2014/5/20/742

So, my suggestion is follows:

1) printk
Keeps current implemntation of upstream kernel.
The messages are divided and can be mixed, but all users can check
the error
messages without any settings.

2) traceevents
To get the complete messages, we can use ftrace or perf (or
something on them).
Users can always understand correct messages, but they need to set
up the
tracers.

This patch set is based on Hannes' logging branch:
http://git.kernel.org/cgit/linux/kernel/git/hare/scsi-devel.git/log/?h=logging


[1/10] ~  [6/10]: just cleanup for logging branch
[7/10] ~ [10/10]: introduce new traceevents

Any comments are welcome!


In sg3_utils there are now string yielding equivalents
to the sense buffer print functions. They take a form
like this:
   char * get_sense_str(const unsigned char * sense_buffer,
int sb_len, int blen, char * b);

So this just does the hard work of decoding the sense buffer
(or saying it is invalid) the result of which it places in
buffer 'b'. And 'b' is returned (so this function can be in
the arguments of a driver's printing function).

Adding such string functions would give other parts of the
SCSI subsystem the capability of tailoring their own
messages that include sense data information.


Existing sense buffer print function could be kept and
implemented using the newer _str variants. Would that
be worth the trouble?


Hmm. Probably not.

I would rather go the approach we've been taking with the
VPD pages, and do _not_ decode any sense code data
(except from the usual sense key/ASC/ASCQ values, of course).
Instead we should rather ensure that we can get to the raw
sense code values from userspace so that we can interpret
it later with userspace tools.

My plan for updating scsi logging is:

- move all lone 'printk' statements into dev_printk() variants
  and ensure they are printed in one line to avoid breaking
  logging statements up under high load
- Update scsi_trace to use the functionality from constants.c
- Convert the current scsi_logging mechanism over to tracepoints.

The first bit is mostly done; I'll be sending the patchset for review.
The hard part is the third bit; would be really grand if we can
model this with the existing scsi_logging_level interface intact.
But not sure if that's possible nor if it's desirable.

Btw, _now_ would be a good chance to send an update of constants.c
with latest SPC bits ...

Cheers,

Hannes
--
Dr. Hannes Reinecke   zSeries  Storage
h...@suse.de  +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-27 Thread Douglas Gilbert

On 14-08-27 10:23 AM, Hannes Reinecke wrote:

On 08/08/2014 03:07 PM, Douglas Gilbert wrote:

On 14-08-08 01:50 PM, Yoshihiro YUNOMAE wrote:

Hi All,

This patch set introduces new traceevents in order to output
continuous error
messages. Current SCSI printk messages in upstream kernel can be
divided by and
mixed with other messages. Even if each error message has its
device id,
sometimes we can easily be lost in mixed logs because the
message's device id
is separated from it's body. To avoid it, I'd like to use
traceevents to
store error messages into the ftrace or perf buuffer, because
traceevents
are atomically commited to the buffer.

In this patch set, all printk messages are removed based on a local
discussion with Hannes, but I think printk messages should be kept
because all
users don't enable traceevents and rsyslog can store as files.

However, if printk of logging branch is kept, the messages are
duplicate and
it can induce stack overflow by using local buffer(*1).

  (*1) https://lkml.org/lkml/2014/5/20/742

So, my suggestion is follows:

1) printk
Keeps current implemntation of upstream kernel.
The messages are divided and can be mixed, but all users can check
the error
messages without any settings.

2) traceevents
To get the complete messages, we can use ftrace or perf (or
something on them).
Users can always understand correct messages, but they need to set
up the
tracers.

This patch set is based on Hannes' logging branch:
http://git.kernel.org/cgit/linux/kernel/git/hare/scsi-devel.git/log/?h=logging


[1/10] ~  [6/10]: just cleanup for logging branch
[7/10] ~ [10/10]: introduce new traceevents

Any comments are welcome!


In sg3_utils there are now string yielding equivalents
to the sense buffer print functions. They take a form
like this:
   char * get_sense_str(const unsigned char * sense_buffer,
int sb_len, int blen, char * b);

So this just does the hard work of decoding the sense buffer
(or saying it is invalid) the result of which it places in
buffer 'b'. And 'b' is returned (so this function can be in
the arguments of a driver's printing function).

Adding such string functions would give other parts of the
SCSI subsystem the capability of tailoring their own
messages that include sense data information.


Existing sense buffer print function could be kept and
implemented using the newer _str variants. Would that
be worth the trouble?


Hmm. Probably not.

I would rather go the approach we've been taking with the
VPD pages, and do _not_ decode any sense code data
(except from the usual sense key/ASC/ASCQ values, of course).
Instead we should rather ensure that we can get to the raw
sense code values from userspace so that we can interpret
it later with userspace tools.

My plan for updating scsi logging is:

- move all lone 'printk' statements into dev_printk() variants
   and ensure they are printed in one line to avoid breaking
   logging statements up under high load
- Update scsi_trace to use the functionality from constants.c
- Convert the current scsi_logging mechanism over to tracepoints.

The first bit is mostly done; I'll be sending the patchset for review.
The hard part is the third bit; would be really grand if we can
model this with the existing scsi_logging_level interface intact.
But not sure if that's possible nor if it's desirable.

Btw, _now_ would be a good chance to send an update of constants.c
with latest SPC bits ...


From constants.c:
 * Updated to SPC-4 T10/1713-D Rev 36g, D. Gilbert 20130701

Not much has changed between then and now (37a). There is a
lot pending for SPC-5 plus all the ZBC stuff, little of which
has hit the drafts yet. WRITE ATOMIC and a few new asc/ascq
codes is about all that I have noticed. Even when new asc/ascq
strings are approved, it needs the SPC4/5 technical editor to
allocate numbers for them.

So even if the timing is good from the kernel POV, not much
is available. The next T10 meeting is in a few weeks, lets
see what happens there.

Doug Gilbert


--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-26 Thread Hannes Reinecke

On 08/22/2014 02:39 AM, Elliott, Robert (Server Storage) wrote:

-Original Message-
From: linux-scsi-ow...@vger.kernel.org [mailto:linux-scsi-
ow...@vger.kernel.org] On Behalf Of Yoshihiro YUNOMAE
Sent: Friday, 08 August, 2014 6:50 AM
Subject: [RFC PATCH -logging 00/10] scsi/constants: Output continuous
error messages on trace

...

1) printk
Keeps current implemntation of upstream kernel.
The messages are divided and can be mixed, but all users can
check the error messages without any settings.


scsi_io_completion ignore the scsi_logging_level and always calls
printk if it detects ACTION_FAIL, resulting in messages like:

 [10240.338600] sd 2:0:0:0: [sdr]
 [10240.339722] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
 [10240.341662] sd 2:0:0:0: [sdr]
 [10240.342792] Sense Key : Hardware Error [current]
 [10240.344575] sd 2:0:0:0: [sdr]
 [10240.345653] Add. Sense: Logical unit failure
 [10240.347138] sd 2:0:0:0: [sdr] CDB:
 [10240.348309] Read(10): 28 00 00 00 00 80 00 00 08 00

If you trigger hundreds of errors (e.g., hot remove a device
during heavy IO), then all the prints to the linux serial console
bog down the system, causing timeouts in commands to other
devices and soft lockups for applications.

Some changes that would help are:
1. Put them under SCSI logging level control
2. Use printk_ratelimited so an excessive number are trimmed

Would you like to include something like this in your
patch set?

This is an example patch that only prints them if the MLCOMPLETE
logging level is nonzero.
Off: scsi_logging_level --set --mlcomplete=0
On: scsi_logging_level --set --mlcomplete=1

Some other loglevel (e.g., ERROR_RECOVERY) could be used.

diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
index d6b4ea8..dbb601f 100644
--- a/drivers/scsi/scsi_lib.c
+++ b/drivers/scsi/scsi_lib.c
@@ -1037,7 +1037,9 @@ void scsi_io_completion(struct scsi_cmnd *cmd, unsigned 
int good_bytes)
switch (action) {
case ACTION_FAIL:
/* Give up and fail the remainder of the request */
-   if (!(req-cmd_flags  REQ_QUIET)) {
+   if (!(req-cmd_flags  REQ_QUIET) 
+   SCSI_LOG_LEVEL(SCSI_LOG_MLCOMPLETE_SHIFT,
+   SCSI_LOG_MLCOMPLETE_BITS)) {
scsi_print_result(cmd);
if (driver_byte(result)  DRIVER_SENSE)
scsi_print_sense(, cmd);

Converting to printk_ratelimited is harder since the prints
are spread out over three functions (and as your patch
series notes, many individual printk calls).  The rates
for the printk calls might not match, which would lead to
even more confusing output.


Good point. Will be including it.

Cheers,

Hannes
--
Dr. Hannes Reinecke   zSeries  Storage
h...@suse.de  +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-26 Thread Hannes Reinecke

On 08/22/2014 09:54 PM, Douglas Gilbert wrote:

On 14-08-12 11:13 PM, Yoshihiro YUNOMAE wrote:

Hi Douglas,

Thank you for your comment.

(2014/08/08 22:07), Douglas Gilbert wrote:

On 14-08-08 01:50 PM, Yoshihiro YUNOMAE wrote:

Hi All,

This patch set introduces new traceevents in order to output
continuous error
messages. Current SCSI printk messages in upstream kernel can be
divided by and
mixed with other messages. Even if each error message has its
device id,
sometimes we can easily be lost in mixed logs because the message's
device id
is separated from it's body. To avoid it, I'd like to use
traceevents to
store error messages into the ftrace or perf buuffer, because
traceevents
are atomically commited to the buffer.

In this patch set, all printk messages are removed based on a local
discussion with Hannes, but I think printk messages should be kept
because all
users don't enable traceevents and rsyslog can store as files.

However, if printk of logging branch is kept, the messages are
duplicate and
it can induce stack overflow by using local buffer(*1).

  (*1) https://lkml.org/lkml/2014/5/20/742

So, my suggestion is follows:

1) printk
Keeps current implemntation of upstream kernel.
The messages are divided and can be mixed, but all users can
check the
error
messages without any settings.

2) traceevents
To get the complete messages, we can use ftrace or perf (or
something
on them).
Users can always understand correct messages, but they need to
set up the
tracers.

This patch set is based on Hannes' logging branch:
http://git.kernel.org/cgit/linux/kernel/git/hare/scsi-devel.git/log/?h=logging



[1/10] ~  [6/10]: just cleanup for logging branch
[7/10] ~ [10/10]: introduce new traceevents

Any comments are welcome!


In sg3_utils there are now string yielding equivalents
to the sense buffer print functions. They take a form
like this:
   char * get_sense_str(const unsigned char * sense_buffer,
int sb_len, int blen, char * b);

So this just does the hard work of decoding the sense buffer
(or saying it is invalid) the result of which it places in
buffer 'b'. And 'b' is returned (so this function can be in
the arguments of a driver's printing function).

Adding such string functions would give other parts of the
SCSI subsystem the capability of tailoring their own
messages that include sense data information.


Existing sense buffer print function could be kept and
implemented using the newer _str variants. Would that
be worth the trouble?


I have already sent the idea using local buffer on this February,
but it was rejected by James (*1). By using stack region for local
buffer, stack overflow can occur. So, I implemented this feature
to atomically output an error message with device information.

(*1) https://lkml.org/lkml/2014/5/20/742


Hi,
In the _str variants that I referred to, the caller provides
the buffer and its length. The responsibility of the
implementation of those _str variants is to use that
buffer, not exceed it, and make sure that it is null terminated
on return.

Can't see any inherent threat to the stack size there, and if
there is then that is just bad design by the caller.

The advantage of the _str variants is that the caller can
supply context and print/log a more useful message, perhaps
including the caller's __func__ . That message could include
sense information (perhaps truncated to 128 bytes, say),
and be output as a single unit.

IMO too many log messages are multi-line and in a noisy,
misbehaving system those messages can be interleaved
with other noise making them difficult to decipher.


Precisely, and that is what my patchset is trying to address.

I'm currently porting it to core-for-3.18, will be posting it
for review once it's done.

Cheers,

Hannes
--
Dr. Hannes Reinecke   zSeries  Storage
h...@suse.de  +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: scsi logging future directions, was Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-25 Thread Hannes Reinecke

On 08/24/2014 10:44 PM, Christoph Hellwig wrote:

On Fri, Aug 22, 2014 at 12:39:59AM +, Elliott, Robert (Server Storage) 
wrote:

If you trigger hundreds of errors (e.g., hot remove a device
during heavy IO), then all the prints to the linux serial console
bog down the system, causing timeouts in commands to other
devices and soft lockups for applications.

Some changes that would help are:
1. Put them under SCSI logging level control
2. Use printk_ratelimited so an excessive number are trimmed

Would you like to include something like this in your
patch set?


I think we should come to an agreement where we want to go with scsi
logging first before doing various smaller adjustments.  (Although your
example is one that's urgent enough that I'd like to put it in ASAP,
I had issues with it a few times).

I had a chat with Martin at Linuxcon about these issues, and we were
both in favor of getting rid of the old scsi logging mechansisms and
instead replace it by an extended version of the scsi tracepoints that
cover all places, and dump all data from the old logging mechanism
that people find useful.

In a few places we'd still want to log normal dev_printk style errors,
and the I/O completion is one of them, even if they really need to be
ratelimited and condensed.

If someone has arguments in favour of keeping the old logging code
I'd love to hear them, but in practive the traceevent code has huge
benefits:

  - almost zero overhead if disabled
  - can easily be used without any tools through configs, but can be used
even better with tools like trace-cmd or perf
  - allows both fine and coarse grained selections of events to trace
  - allows to capture statistics on each trace point without event enabling the
output
  - doesn't have any of the console lockup problems.

I've already been working on updating scsi logging infrastructure, 
removing old cludges and streamlining it.
I'm all in favour of moving things over to scsi tracing; in fact I've 
already moved all the current SCSI_ML_XXX statements to tracepoints in

my current patchset.

Unfortunately I haven't found time to test things out there, and there's 
the patchset from Yoshihiro which needs review and integration.


As of now I've treated this as rather low priority as no-one seemed to 
mind and the patchsets will be touching each and every driver.


I'll be updating the patchset and send it for review.

Cheers,

Hannes
--
Dr. Hannes Reinecke   zSeries  Storage
h...@suse.de  +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


scsi logging future directions, was Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-24 Thread Christoph Hellwig
On Fri, Aug 22, 2014 at 12:39:59AM +, Elliott, Robert (Server Storage) 
wrote:
 If you trigger hundreds of errors (e.g., hot remove a device
 during heavy IO), then all the prints to the linux serial console
 bog down the system, causing timeouts in commands to other
 devices and soft lockups for applications.
 
 Some changes that would help are:
 1. Put them under SCSI logging level control
 2. Use printk_ratelimited so an excessive number are trimmed
 
 Would you like to include something like this in your
 patch set?

I think we should come to an agreement where we want to go with scsi
logging first before doing various smaller adjustments.  (Although your
example is one that's urgent enough that I'd like to put it in ASAP,
I had issues with it a few times).

I had a chat with Martin at Linuxcon about these issues, and we were
both in favor of getting rid of the old scsi logging mechansisms and
instead replace it by an extended version of the scsi tracepoints that
cover all places, and dump all data from the old logging mechanism
that people find useful.

In a few places we'd still want to log normal dev_printk style errors,
and the I/O completion is one of them, even if they really need to be
ratelimited and condensed.

If someone has arguments in favour of keeping the old logging code
I'd love to hear them, but in practive the traceevent code has huge
benefits:

 - almost zero overhead if disabled
 - can easily be used without any tools through configs, but can be used
   even better with tools like trace-cmd or perf
 - allows both fine and coarse grained selections of events to trace
 - allows to capture statistics on each trace point without event enabling the
   output
 - doesn't have any of the console lockup problems.

--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-22 Thread Douglas Gilbert

On 14-08-12 11:13 PM, Yoshihiro YUNOMAE wrote:

Hi Douglas,

Thank you for your comment.

(2014/08/08 22:07), Douglas Gilbert wrote:

On 14-08-08 01:50 PM, Yoshihiro YUNOMAE wrote:

Hi All,

This patch set introduces new traceevents in order to output
continuous error
messages. Current SCSI printk messages in upstream kernel can be
divided by and
mixed with other messages. Even if each error message has its device id,
sometimes we can easily be lost in mixed logs because the message's
device id
is separated from it's body. To avoid it, I'd like to use traceevents to
store error messages into the ftrace or perf buuffer, because traceevents
are atomically commited to the buffer.

In this patch set, all printk messages are removed based on a local
discussion with Hannes, but I think printk messages should be kept
because all
users don't enable traceevents and rsyslog can store as files.

However, if printk of logging branch is kept, the messages are
duplicate and
it can induce stack overflow by using local buffer(*1).

  (*1) https://lkml.org/lkml/2014/5/20/742

So, my suggestion is follows:

1) printk
Keeps current implemntation of upstream kernel.
The messages are divided and can be mixed, but all users can check the
error
messages without any settings.

2) traceevents
To get the complete messages, we can use ftrace or perf (or something
on them).
Users can always understand correct messages, but they need to set up the
tracers.

This patch set is based on Hannes' logging branch:
http://git.kernel.org/cgit/linux/kernel/git/hare/scsi-devel.git/log/?h=logging


[1/10] ~  [6/10]: just cleanup for logging branch
[7/10] ~ [10/10]: introduce new traceevents

Any comments are welcome!


In sg3_utils there are now string yielding equivalents
to the sense buffer print functions. They take a form
like this:
   char * get_sense_str(const unsigned char * sense_buffer,
int sb_len, int blen, char * b);

So this just does the hard work of decoding the sense buffer
(or saying it is invalid) the result of which it places in
buffer 'b'. And 'b' is returned (so this function can be in
the arguments of a driver's printing function).

Adding such string functions would give other parts of the
SCSI subsystem the capability of tailoring their own
messages that include sense data information.


Existing sense buffer print function could be kept and
implemented using the newer _str variants. Would that
be worth the trouble?


I have already sent the idea using local buffer on this February,
but it was rejected by James (*1). By using stack region for local
buffer, stack overflow can occur. So, I implemented this feature
to atomically output an error message with device information.

(*1) https://lkml.org/lkml/2014/5/20/742


Hi,
In the _str variants that I referred to, the caller provides
the buffer and its length. The responsibility of the
implementation of those _str variants is to use that
buffer, not exceed it, and make sure that it is null terminated
on return.

Can't see any inherent threat to the stack size there, and if
there is then that is just bad design by the caller.

The advantage of the _str variants is that the caller can
supply context and print/log a more useful message, perhaps
including the caller's __func__ . That message could include
sense information (perhaps truncated to 128 bytes, say),
and be output as a single unit.

IMO too many log messages are multi-line and in a noisy,
misbehaving system those messages can be interleaved
with other noise making them difficult to decipher.

Doug Gilbert


--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


RE: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-21 Thread Elliott, Robert (Server Storage)
 -Original Message-
 From: linux-scsi-ow...@vger.kernel.org [mailto:linux-scsi-
 ow...@vger.kernel.org] On Behalf Of Yoshihiro YUNOMAE
 Sent: Friday, 08 August, 2014 6:50 AM
 Subject: [RFC PATCH -logging 00/10] scsi/constants: Output continuous
 error messages on trace
...
 1) printk
 Keeps current implemntation of upstream kernel.
 The messages are divided and can be mixed, but all users can
 check the error messages without any settings.

scsi_io_completion ignore the scsi_logging_level and always calls
printk if it detects ACTION_FAIL, resulting in messages like:

[10240.338600] sd 2:0:0:0: [sdr]
[10240.339722] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[10240.341662] sd 2:0:0:0: [sdr]
[10240.342792] Sense Key : Hardware Error [current]
[10240.344575] sd 2:0:0:0: [sdr]
[10240.345653] Add. Sense: Logical unit failure
[10240.347138] sd 2:0:0:0: [sdr] CDB:
[10240.348309] Read(10): 28 00 00 00 00 80 00 00 08 00

If you trigger hundreds of errors (e.g., hot remove a device
during heavy IO), then all the prints to the linux serial console
bog down the system, causing timeouts in commands to other
devices and soft lockups for applications.

Some changes that would help are:
1. Put them under SCSI logging level control
2. Use printk_ratelimited so an excessive number are trimmed

Would you like to include something like this in your
patch set?

This is an example patch that only prints them if the MLCOMPLETE 
logging level is nonzero.
Off: scsi_logging_level --set --mlcomplete=0
On: scsi_logging_level --set --mlcomplete=1

Some other loglevel (e.g., ERROR_RECOVERY) could be used.

diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
index d6b4ea8..dbb601f 100644
--- a/drivers/scsi/scsi_lib.c
+++ b/drivers/scsi/scsi_lib.c
@@ -1037,7 +1037,9 @@ void scsi_io_completion(struct scsi_cmnd *cmd, unsigned 
int good_bytes)
switch (action) {
case ACTION_FAIL:
/* Give up and fail the remainder of the request */
-   if (!(req-cmd_flags  REQ_QUIET)) {
+   if (!(req-cmd_flags  REQ_QUIET) 
+   SCSI_LOG_LEVEL(SCSI_LOG_MLCOMPLETE_SHIFT,
+   SCSI_LOG_MLCOMPLETE_BITS)) {
scsi_print_result(cmd);
if (driver_byte(result)  DRIVER_SENSE)
scsi_print_sense(, cmd);

Converting to printk_ratelimited is harder since the prints
are spread out over three functions (and as your patch
series notes, many individual printk calls).  The rates
for the printk calls might not match, which would lead to
even more confusing output.

---
Rob ElliottHP Server Storage





Re: Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-12 Thread Yoshihiro YUNOMAE

Hi Douglas,

Thank you for your comment.

(2014/08/08 22:07), Douglas Gilbert wrote:

On 14-08-08 01:50 PM, Yoshihiro YUNOMAE wrote:

Hi All,

This patch set introduces new traceevents in order to output
continuous error
messages. Current SCSI printk messages in upstream kernel can be
divided by and
mixed with other messages. Even if each error message has its device id,
sometimes we can easily be lost in mixed logs because the message's
device id
is separated from it's body. To avoid it, I'd like to use traceevents to
store error messages into the ftrace or perf buuffer, because traceevents
are atomically commited to the buffer.

In this patch set, all printk messages are removed based on a local
discussion with Hannes, but I think printk messages should be kept
because all
users don't enable traceevents and rsyslog can store as files.

However, if printk of logging branch is kept, the messages are
duplicate and
it can induce stack overflow by using local buffer(*1).

  (*1) https://lkml.org/lkml/2014/5/20/742

So, my suggestion is follows:

1) printk
Keeps current implemntation of upstream kernel.
The messages are divided and can be mixed, but all users can check the
error
messages without any settings.

2) traceevents
To get the complete messages, we can use ftrace or perf (or something
on them).
Users can always understand correct messages, but they need to set up the
tracers.

This patch set is based on Hannes' logging branch:
http://git.kernel.org/cgit/linux/kernel/git/hare/scsi-devel.git/log/?h=logging


[1/10] ~  [6/10]: just cleanup for logging branch
[7/10] ~ [10/10]: introduce new traceevents

Any comments are welcome!


In sg3_utils there are now string yielding equivalents
to the sense buffer print functions. They take a form
like this:
   char * get_sense_str(const unsigned char * sense_buffer,
int sb_len, int blen, char * b);

So this just does the hard work of decoding the sense buffer
(or saying it is invalid) the result of which it places in
buffer 'b'. And 'b' is returned (so this function can be in
the arguments of a driver's printing function).

Adding such string functions would give other parts of the
SCSI subsystem the capability of tailoring their own
messages that include sense data information.


Existing sense buffer print function could be kept and
implemented using the newer _str variants. Would that
be worth the trouble?


I have already sent the idea using local buffer on this February,
but it was rejected by James (*1). By using stack region for local
buffer, stack overflow can occur. So, I implemented this feature
to atomically output an error message with device information.

(*1) https://lkml.org/lkml/2014/5/20/742

Thanks,
Yoshihiro YUNOMAE

--
Yoshihiro YUNOMAE
Software Platform Research Dept. Linux Technology Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: yoshihiro.yunomae...@hitachi.com


--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [RFC PATCH -logging 00/10] scsi/constants: Output continuous error messages on trace

2014-08-08 Thread Douglas Gilbert

On 14-08-08 01:50 PM, Yoshihiro YUNOMAE wrote:

Hi All,

This patch set introduces new traceevents in order to output continuous error
messages. Current SCSI printk messages in upstream kernel can be divided by and
mixed with other messages. Even if each error message has its device id,
sometimes we can easily be lost in mixed logs because the message's device id
is separated from it's body. To avoid it, I'd like to use traceevents to
store error messages into the ftrace or perf buuffer, because traceevents
are atomically commited to the buffer.

In this patch set, all printk messages are removed based on a local
discussion with Hannes, but I think printk messages should be kept because all
users don't enable traceevents and rsyslog can store as files.

However, if printk of logging branch is kept, the messages are duplicate and
it can induce stack overflow by using local buffer(*1).

  (*1) https://lkml.org/lkml/2014/5/20/742

So, my suggestion is follows:

1) printk
Keeps current implemntation of upstream kernel.
The messages are divided and can be mixed, but all users can check the error
messages without any settings.

2) traceevents
To get the complete messages, we can use ftrace or perf (or something on them).
Users can always understand correct messages, but they need to set up the
tracers.

This patch set is based on Hannes' logging branch:
http://git.kernel.org/cgit/linux/kernel/git/hare/scsi-devel.git/log/?h=logging

[1/10] ~  [6/10]: just cleanup for logging branch
[7/10] ~ [10/10]: introduce new traceevents

Any comments are welcome!


In sg3_utils there are now string yielding equivalents
to the sense buffer print functions. They take a form
like this:
  char * get_sense_str(const unsigned char * sense_buffer,
   int sb_len, int blen, char * b);

So this just does the hard work of decoding the sense buffer
(or saying it is invalid) the result of which it places in
buffer 'b'. And 'b' is returned (so this function can be in
the arguments of a driver's printing function).

Adding such string functions would give other parts of the
SCSI subsystem the capability of tailoring their own
messages that include sense data information.


Existing sense buffer print function could be kept and
implemented using the newer _str variants. Would that
be worth the trouble?

Doug Gilbert


--
To unsubscribe from this list: send the line unsubscribe linux-scsi in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html