regarding ata_msg_*()

Hello, Jeff, Borislav.

I looked through the ata_msg_*() changes and read Donald Becker's message about network driver message control. This is needed facility and I agree with general direction, but I have slightly different ideas about details.

We currently have the following message categories.

	ATA_MSG_DRV	= 0x0001,
	ATA_MSG_INFO	= 0x0002,
	ATA_MSG_PROBE	= 0x0004,
	ATA_MSG_WARN	= 0x0008,
	ATA_MSG_MALLOC	= 0x0010,
	ATA_MSG_CTL	= 0x0020,
	ATA_MSG_INTR	= 0x0040,
	ATA_MSG_ERR	= 0x0080,

* I have no idea what CTL means or why DRV is used in ata_dev_disable().

* By default, ATA_MSG_INFO is turned off, which means ata_dev_configure() doesn't print anything about newly detected and configured device, which isn't good (BTW, why is @print_info completely ignored in that function? It's needed. We don't want to print those messages when we're just revalidating devices.) Unfortunately, if I enable ATA_MSG_INFO, I enable some of function ENTER/EXIT messages, too. Bah...

* In ata_dev_configure(), some ENTER/EXIT messages are INFO while others are PROBE.

* In ata_dev_read_id(), ENTER message is CTL, what is CTL? What makes ata_port_flush_task() and ata_dev_read_id() share CTL? And, why are flush#2/EXIT messages CTL while ENTER/flush#1 are left as DPRINTK?

All of the above problems are introduced during single sweep conversion over libata-core.c. It might be that it simply was a bad sweep, but with the current ambiguous definitions, I don't think things will be any better when different people try to use those message types on various LLDs.

So, please make things *much* simpler. I think it's overly elaborate to categorize normal (non-debug) messages by message types. In my experience, such categorization usually ends up mis-categorization - you know, "Is this PROBE or CTL? who cares? make it INFO. Is INFO debug or normal message? WTF..."

IMHO, it's enough to have non-debug messages categorized by verbosity - CRIT, ERR, WARN and INFO and all of them enabled by default. This also forces developers to suppress the urge to be whiny and refine their messages. Maybe we can add one more level below INFO for slightly-verbose but not quite debug, but I think we're better off without it.

For debug messages, we probably need some categorization to separate LLD message from core messages and suppress command issue/completion debug messages unless strictly necessary, etc... But, those categories MUST be made by necessities (e.g. issue/completion messages suffocates other messages, so they need separate slot.) not by some logical out-of-the-blue categorization. Otherwise, we end up with categories which may be obvious to some but not so to others and things will get messy.

Thanks.

tejun

On Sun, Jun 25, 2006 at 09:21:13PM +0900, Tejun Heo wrote:

Morning,

These all are different debugging levels which I proposed leaning on D. Becker's mail, see linux-ide archives from 25 Aug 2005. I agree that the debugging levels are somewhat "off-course" but this was not the main concern when sending the patches. Instead, we aimed first at the complete conversion to the new scheme and then reajusting dbbg levels, so this is that...

In this mail it says also what CTL means and since nobody opposed to that I went on preparing the patches.

My bad, it seems I've missed those, but there are some cases like ata_dev_classify(), for ex., where you simply
don't have an access to ata_dev or ata_port struct in order to issue a message according to the msg_enable status so I left those out for further discussion concerning replacement.

I guess you're right about the laziness/carelessness (no insinuations
whatsoever :)) factor with developers but I still
think it is a good thing to have different debugging levels for different message semantics and messages origin like interrupts, mem allocation, hardware probing, etc. I think, though, it would be better to have the debugging scheme running first and then rehash and reconfigure which debugging levels are appropriate and enough for libata-dev...

Regards,
Boris.

___________________________________________________________
Telefonate ohne weitere Kosten vom PC zum PC: http://messenger.yahoo.de

Hello, Borislav.

I'm sorry that I'm whining now not back then, but better late than never, I guess.

I'll look that up, but whatever it is, please make it apparent in the code - please add some comments after constant definitions at the very least.

[--snip--]

I would be one of the first ones being lazy/careless. Insinuations welcomed. :-)

To some degree, I agree but for example you mentioned mem allocation as one of the categories. The thing is that libata almost never allocates anything during normal operation. Even hotplug/unplugs are performed w/o any memory allocation. Allocations only occur during driver attachment and if allocation fails during that, there's nothing much to do than printing error message and giving up - no need for separate category.

I'm not saying debug message categorization is unnecessary. It will be useful, but let's do it only on as-needed basis. IMHO, that will lead to the least amount of confusion.

My suggestion is to keep the current (pre-msg_enable) model for the first conversion and categorize debug messages further after that. So, message categories will be...

ATA_MSG_ERR
ATA_MSG_WARN
ATA_MSG_INFO
-------------> all above are enabled by default
ATA_MSG_DEBUG
ATA_MSG_VDEBUG

Then, you have 1-to-1 mapping w/ the existing messages. You can simply incorporate message enabled tests into ata_*_printk() functions and the conversion would be trivial.

After that's complete, we can diversify ATA_MSG_DEBUG and ATA_MSG_VDEBUG by separating out chatty ones out. e.g. you can separate out SG mapping/unmapping (including padding) debug messages, which produce massive amount of logs when enabled, into ATA_MSG_SG or something. After several such separations, debug messages should be quite manageable && the categories wouldn't be too elaborate.

Thanks.

tejun

On Mon, Jun 26, 2006 at 05:00:39PM +0900, Tejun Heo wrote:

Hi Tejun,

<snip>

Yes, this sounds logical, I like it, it really fits libata more but at the time I made that msg classification I kinda wanted to stick closely to Becker's initial implementation :). But you're perfectly right, this is the way to go so I'll do that after reading what the others have to say. However, as I said before, IMHO it would be of higher priority now to convert to this new scheme and changing the dbg levels later would be trivial once we got all of libata done.

Regards,
Boris.

___________________________________________________________
Telefonate ohne weitere Kosten vom PC zum PC: http://messenger.yahoo.de

Jeff, what do you think?

Borislav, can you restore configuration messages in ata_dev_configure()?
Those messages need to be printed.

Thanks.

tejun

The current ATA_MSG_xxx were best-guesses, and only now, when the conversion patches begin to be merged, do we see how well those guesses match with reality.

I do agree that the above list matches the current code, but the ATA_MSG_xxx and Becker schemes are aimed more at verbosity+severity levels, than strictly severity levels.

<thinking aloud> For libata, the best mapping might be

0: critical problems (errors)
1: non-critical, recovered problems or "troubling circumstances" (warnings)
2: terse info from exceptional events (probe, hotplug)
3: more verbose info about exceptional events (IDENTIFY hex values as shown today, sector count, features) 4: terse command-submit tracing
5: terse command-complete tracing
6: verbose hot path
7: function ENTER/EXIT tracing

Thus illustrating the general goals of (a) enabling fine-grained tracing of specific portions of libata, (b) ordering messages in order of severity, and (c) ordering messages by likelihood of producing tons of log spam.

Eventually we can use blktool to turn on terse command-complete tracing for a single SATA port, and not have to suffer the current log spam and coarseness that results from using today's #defines.

Jeff

Yeap, agreed.

My point is that as we need selective message enabling, let's do it by first implementing 1:1 mapping and think about message types later. As we already have ata_*_printk() wrappers, embedding ata_msg_*() and converting KERN_* to ATA_MSG_* should be enough.

Generally agreed. I don't think your and my ideas are that different. Mine looks like..

ATA_MSG_ERR
ATA_MSG_WARNING
ATA_MSG_INFO /* I think intial config msg should be in this cat */
(ATA_MSG_VINFO maybe) /* revalidation messages, EH progress... */ -- debug below here
ATA_MSG_DEBUG
ATA_MSG_VDEBUG
ATA_MSG_CMD /* issue / completion */
ATA_MSG_SG /* SG map/unmap handling */
ATA_MGS_TRACE /* function enter/exit */

Yeah, we really need that. I currently use /dev/hda as my root when I need to turn on those debug messages. :-P

tejun