printk: implement printk_header() and merging printk, take #2
Subsystems (2)
PATCH 1/1 printk: implement printk_header() and merging printk, take #2
Hello, all.
This is the second take of implement-printk_header-and-mprintk patchset.
Changes from the last take[L] are...
* s/mprintk_push/mprintk_add/ and other changes suggested by Randy Dunlap.
* mp->buf instead of mp->header to ease freeing kmalloc'd buffer later.
* mprintk multiline log level handling fixed and improved. mp->prv is removed and mp->flags is used to track whether header log level exists and log level is overridden. One critical bug was re-using va_list more than once resulting in dereferences of wrong addresses. Fixed by using va_copy().
This patchset aims to make printing multiline messages and assembling message piece-by-piece easier.
In a nutshell, printk_header() lets you do the following atomically (against other messages).
code:
printk(KERN_INFO "ata1.00: ", "line0\nline1\nline2\n");
output:
<6>ata1.00: line0
<6> line1
<6> line2
And mprintk the following.
code:
DEFINE_MPRINTK(mp, 2 * 80);
mprintk_set_header(&mp, KERN_INFO "ata%u.%2u: ", 1, 0); mprintk_push(&mp, "ATA %d", 7); mprintk_push(&mp, ", %u sectors\n", 1024); mprintk(&mp, "everything seems dandy\n");
output:
<6>ata1.00: ATA 7, 1024 sectors
<6> everything seems dandy
For more info, please read Documentation/printk.txt which is created by the fourth patch.
This patchset is against the current linux-2.6#master (a7da60f4) and contains the following patches.
0001-printk-keep-log-level-on-multiline-messages.patch 0002-printk-implement-v-printk_header.patch 0003-printk-implement-merging-printk.patch 0004-printk-add-Documentation-printk.txt.patch 0005-libata-make-libata-use-printk_header-and-mprintk.patch
Documentation/00-INDEX | 2 Documentation/printk.txt | 711 ++++++++++++++++++++++++++++++++++++++++++++ drivers/ata/libata-core.c | 202 +++++++----- drivers/ata/libata-eh.c | 150 ++++----- drivers/ata/libata-pmp.c | 5 drivers/ata/libata-scsi.c | 6 drivers/ata/sata_inic162x.c | 2 drivers/ata/sata_nv.c | 4 include/linux/kernel.h | 81 +++++ include/linux/libata.h | 35 +- kernel/printk.c | 392 ++++++++++++++++++++++-- 11 files changed, 1379 insertions(+), 211 deletions(-)
Randy, Jeff, if this take gets acked, how about pushing this through libata-dev as it's the first user and I have other libata changes depending on mprintk?
Thanks.
--
tejun
PATCH 1/5 printk: keep log level on multiline messages
When printing multiline messages, printk() resets log level to default_message_loglevel after the first line. This changes log level unexpectedly when printing multiline messages.
For example, libata error messages are printed like the following.
<3>ata8.00: cmd 60/01:00:e0:71:02/00:00:00:00:00/40 tag 0 ncq 512 in
<4> res 40/00:34:de:71:02/00:00:00:00:00/40 Emask 0x10 (ATA bus error)
This patch makes printk use the log level of the last line if the current line doesn't specify log level explicitly.
While at it, separate out is_loglevel() test. This will be used by later changes.
--- kernel/printk.c | 51 ++++++++++++++++++++++++--------------------------- 1 files changed, 24 insertions(+), 27 deletions(-)
kernel/printk.c +24 -27
@@ -628,11 +628,17 @@ asmlinkage int printk(const char *fmt, ...)/* cpu currently holding logbuf_lock */ static volatile unsigned int printk_cpu =UINT_MAX ; +static int is_loglevel (const char *p) +{ +return p[0 ] =='<' && p[1 ] >='0' && p[1 ] <='7' && p[2 ] =='>' ; +} + asmlinkage int vprintk(const char *fmt, va_list args) { +int last_lv = default_message_loglevel;unsigned long flags;int printed_len; -char *p; +const char *p;static char printk_buf[1024 ];static int log_level_unknown =1 ;
@@ -659,48 +665,39 @@ asmlinkage int vprintk(const char *fmt, va_list args)*/ for (p = printk_buf; *p; p++) {if (log_level_unknown) { -/* log_level_unknown signals the start of a new line */ +/* log_level_unknown signals the start of a new line */ +int lv = last_lv; + +if (is_loglevel (p)) { + lv = p[1 ] -'0' ; + p +=3 ; + printed_len -=3 ; + } + +emit_log_char ('<' ); +emit_log_char (lv +'0' ); +emit_log_char ('>' ); + printed_len +=3 ; +if (printk_time) { -int loglev_char;char tbuf[50 ], *tp;unsigned tlen;unsigned long long t;unsigned long nanosec_rem; -/* -* force the log level token to be -* before the time output. -*/ -if (p[0 ] =='<' && p[1 ] >='0' && - p[1 ] <='7' && p[2 ] =='>' ) { - loglev_char = p[1 ]; - p +=3 ; - printed_len -=3 ; - }else { - loglev_char = default_message_loglevel - +'0' ; - } t =printk_clock (); nanosec_rem =do_div (t,1000000000 ); tlen =sprintf (tbuf, -"<%c>[%5lu.%06lu] " , - loglev_char, +"[%5lu.%06lu] " , (unsigned long )t, nanosec_rem/1000 );for (tp = tbuf; tp < tbuf + tlen; tp++)emit_log_char (*tp); printed_len += tlen; - }else { -if (p[0 ] !='<' || p[1 ] <'0' || - p[1 ] >'7' || p[2 ] !='>' ) { -emit_log_char ('<' ); -emit_log_char (default_message_loglevel - +'0' ); -emit_log_char ('>' ); - printed_len +=3 ; - } } + + last_lv = lv; log_level_unknown =0 ;if (!*p)break ;
Signature · 1 line
1.5.2.4
PATCH 2/5 printk: implement [v]printk_header()
In reply to Tejun HeoImplement [v]printk_header() which takes @header argument and automatically prints header in front of or indents multiline messages. For example, if @header is "<7>ata1.00: " and the formatted message is "<6>line0\nline1\n", the following gets written to the console.
<6>ata1.00: line0
<6> line1
Header is printed only on the first lines and when log level changes in the middle in case messages of different log level are sent to different destinations. Other lines are indented the same amount as the length of the header. This helps to distinguish where a multiline message begins when messages of similar pattern repeats, for example...
ata8.00: cmd 60/80:20:e1:71:02/00:00:00:00:00/40 tag 4 ncq 65536 in
res 40/00:34:de:71:02/00:00:00:00:00/40 Emask 0x10 (ATA bus error)
ata8.00: cmd 60/0e:28:d0:71:02/00:00:00:00:00/40 tag 5 ncq 7168 in
res 40/00:34:de:71:02/00:00:00:00:00/40 Emask 0x10 (ATA bus error)
ata8.00: cmd 60/7f:38:61:72:02/00:00:00:00:00/40 tag 7 ncq 65024 in
res 40/00:34:de:71:02/00:00:00:00:00/40 Emask 0x10 (ATA bus error)--- include/linux/kernel.h | 12 ++++++ kernel/printk.c | 94 ++++++++++++++++++++++++++++++++++++++++++++--- 2 files changed, 100 insertions(+), 6 deletions(-)
include/linux/kernel.h +12 -0
@@ -175,6 +175,10 @@ extern struct pid *session_of_pgrp(struct pid *pgrp);extern void dump_thread (struct pt_regs *regs,struct user *dump);#ifdef CONFIG_PRINTK +asmlinkage int vprintk_header(const char *header, const char *fmt, va_list args) + __attribute__ ((format (printf,2 ,0 ))); +asmlinkage int printk_header(const char *header, const char * fmt, ...) + __attribute__ ((format (printf,2 ,3 )))__cold ; asmlinkage int vprintk(const char *fmt, va_list args) __attribute__ ((format (printf,1 ,0 ))); asmlinkage int printk(const char * fmt, ...)
@@ -183,6 +187,14 @@ extern int log_buf_get_len(void);extern int log_buf_read (int idx);extern int log_buf_copy (char *dest,int idx,int len);#else +static inline int vprintk_header (const char *header,const char *s,va_list args) + __attribute__ ((format (printf,2 ,0 ))); +static inline int vprintk_header (const char *header,const char *s,va_list args) +{return 0 ; } +static inline int printk_header (const char *header,const char *s, ...) + __attribute__ ((format (printf,2 ,3 ))); +static inline int __cold printk_header (const char *header,const char *s, ...) +{return 0 ; }static inline int vprintk (const char *s,va_list args) __attribute__ ((format (printf,1 ,0 )));static inline int vprintk (const char *s,va_list args) {return 0 ; }
kernel/printk.c +88 -6
131 lines not on this page · raw message
Signature · 1 line
1.5.2.4
PATCH 3/5 printk: implement merging printk
In reply to Tejun HeoThere often are times printk messages need to be assembled piece by piece and it's usually done using one of the following methods.
* Calling printk() on partial message segments. This used to be quite common but has a problem - the message can break up if someone else prints something in the middle.
* Prepping a temp buffer and build message piece-by-piece using snprintf(). This is the most generic solution but corner case handling can be tedious and on overflow messages can be lost and such overflows would go unnoticed if overflow detection isn't properly done.
* Collect all the partial data and perform printk() once with all the parameters. This is often combined with the second. This usually works but printing messages can become non-trivial programming problem and can get quite tedious if the message format varies depending on data.
None of the above is quite satisfactory. This patch implement merging printk - mprintk to deal with this problem. It's basically a helper to construct message piece-by-piece into the specified buffer. The caller still has to care about buffer size and how the buffer is allocated but mprintk makes it easier.
* DEFINE_MPRINTK() macro makes it easy to define a mprintk instance with on-stack buffer. Malloc'd buffer can also be used.
* Message is never lost. On buffer overflow, all queued and to be queued messages are printed followed by warning message and stack dump. The warning message and stack dump are printed only once per mprintk instance. The caller also doesn't have to handle buffer malloc failure. If buffer is initialized to NULL, mprintk simply bypasses the messages to printk().
* Has good support for multiline messages. A mprintk instance can have header associated with it and the header can have log level. Header log level is used if a partial message doesn't specify log level explicitly. When log level is specified explicitly in a partial message, the log level is applied to the partial message only.
A simple example.
DEFINE_MPRINTK(mp, 2 * 80); mprintk_set_header(&mp, KERN_DEBUG "ata%u.%2u: ", 1, 0); mprintk_push(&mp, "ATA %d", 7); mprintk_push(&mp, ", %u sectors\n", 1024); mprintk(&mp, "everything seems dandy\n");
Which will be printed like the following as a single message.
<7>ata1.00: ATA 7, 1024 sectors
<7> everything seems dandy
--- include/linux/kernel.h | 69 +++++++++++++ kernel/printk.c | 253 ++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 322 insertions(+), 0 deletions(-)
include/linux/kernel.h +69 -0
@@ -175,6 +175,27 @@ extern struct pid *session_of_pgrp(struct pid *pgrp);extern void dump_thread (struct pt_regs *regs,struct user *dump);#ifdef CONFIG_PRINTK +struct mprintk { +char *buf; +char *body; +char *cur; +char *end; +unsigned int flags; +}; + +#define MPRINTK_INITIALIZER (_buf, _size) \ + { \ + .buf = _buf, \ + .body = _buf, \ + .cur = _buf, \ + .end = _buf + _size, \ + .flags = 0 \ + } + +#define DEFINE_MPRINTK (name, size) \ + char __##name##_buf[size]; \ + struct mprintk name = MPRINTK_INITIALIZER(__##name##_buf, size) + asmlinkage int vprintk_header(const char *header, const char *fmt, va_list args) __attribute__ ((format (printf,2 ,0 ))); asmlinkage int printk_header(const char *header, const char * fmt, ...)
@@ -183,10 +204,33 @@ asmlinkage int vprintk(const char *fmt, va_list args) __attribute__ ((format (printf, 1, 0))); asmlinkage int printk(const char * fmt, ...) __attribute__ ((format (printf,1 ,2 )))__cold ; + +static inline void mprintk_init (struct mprintk *mp,char *buf,size_t size) +{ + *mp = (struct mprintk )MPRINTK_INITIALIZER (buf, size); +} +extern int vmprintk_add (struct mprintk *mp,const char *fmt,va_list args) + __attribute__ ((format (printf,2 ,0 ))); +extern int vmprintk_set_header (struct mprintk *mp,const char *fmt,va_list args) + __attribute__ ((format (printf,2 ,0 ))); +extern int vmprintk (struct mprintk *mp,const char *fmt,va_list args) + __attribute__ ((format (printf,2 ,0 ))); +extern int mprintk_add (struct mprintk *mp,const char *fmt, ...) + __attribute__ ((format (printf,2 ,3 ))); +extern int mprintk_set_header (struct mprintk *mp,const char *fmt, ...) + __attribute__ ((format (printf,2 ,3 ))); +extern int mprintk (struct mprintk *mp,const char *fmt, ...) + __attribute__ ((format (printf,2 ,3 ))); +extern int log_buf_get_len (void );extern int log_buf_read (int idx);extern int log_buf_copy (char *dest,int idx,int len);#else +struct mprintk { }; +#define MPRINTK_INITIALIZER (_buf, _size) { } +#define DEFINE_MPRINTK (name, size) \ + struct mprintk name = __MPRINTK_INITIALIZER(NULL, size) +static inline int vprintk_header (const char *header,const char *s,va_list args) __attribute__ ((format (printf,2 ,0 )));static inline int vprintk_header (const char *header,const char *s,va_list args)
@@ -201,6 +245,31 @@ static inline int vprintk(const char *s, va_list args) { return 0; }static inline int printk (const char *s, ...) __attribute__ ((format (printf,1 ,2 )));static inline int __cold printk (const char *s, ...) {return 0 ; } +static inline void mprintk_init (struct mprintk *mp,char *buf,size_t size) { } +static inline int vmprintk_add (struct mprintk *mp,const char *fmt,va_list args) + __attribute__ ((format (printf,2 ,0 ))); +static inline int vmprintk_add (struct mprintk *mp,const char *fmt,va_list args) +{return 0 ; } +static inline int vmprintk_set_header (struct mprintk *mp,const char *fmt,va_list args) + __attribute__ ((format (printf,2 ,0 ))); +static inline int vmprintk_set_header (struct mprintk *mp,const char *fmt,va_list args) +{return 0 ; } +static inline int vmprintk (struct mprintk *mp,const char *fmt,va_list args) + __attribute__ ((format (printf,2 ,0 ))); +static inline int vmprintk (struct mprintk *mp,const char *fmt,va_list args) +{return 0 ; } +static inline int mprintk_add (struct mprintk *mp,const char *fmt, ...) + __attribute__ ((format (printf,2 ,3 ))); +static inline int mprintk_add (struct mprintk *mp,const char *fmt, ...) +{return 0 ; } +static inline int mprintk_set_header (struct mprintk *mp,const char *fmt, ...) + __attribute__ ((format (printf,2 ,3 ))); +static inline int mprintk_set_header (struct mprintk *mp,const char *fmt, ...) +{return 0 ; } +static inline int mprintk (struct mprintk *mp,const char *fmt, ...) + __attribute__ ((format (printf,2 ,3 ))); +static inline int mprintk (struct mprintk *mp,const char *fmt, ...) +{return 0 ; }static inline int log_buf_get_len (void ) {return 0 ; }static inline int log_buf_read (int idx) {return 0 ; }static inline int log_buf_copy (char *dest,int idx,int len) {return 0 ; }
kernel/printk.c +253 -0
265 lines not on this page · raw message
Signature · 1 line
1.5.2.4
PATCH 4/5 printk: add Documentation/printk.txt
In reply to Tejun HeoAdd Documentation/printk.txt which explains printk, mprintk and their friends.
--- Documentation/00-INDEX | 2 + Documentation/printk.txt | 711 ++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 713 insertions(+), 0 deletions(-) create mode 100644 Documentation/printk.txt
Documentation/00-INDEX +2 -0
@@ -310,6 +310,8 @@ powerpc/ - directory with info on using Linux with the PowerPC. preempt-locking.txt - info on locking under a preemptive kernel. +printk.txt + - info on printk and mprintk. prio_tree.txt - info on radix-priority-search-tree use for indexing vmas. ramdisk.txt
Documentation/printk.txt new file +711 -0
711 lines not on this page · raw message
Signature · 1 line
1.5.2.4
PATCH 5/5 libata: make libata use printk_header() and mprintk
In reply to Tejun HeoReimplement libata printk helpers using printk_header, implement helpers to initialize mprintk and use mprintk during device configuration and EH reporting.
This fixes various formatting related problems of libata messages such as misaligned multiline messages, decoded register lines with leading headers making them difficult to tell to which error they belong to, awkward manual indents and complex message printing logics. More importantly, by making message assembly flexible, this patch makes future changes to device configuration and EH reporting easier.
--- drivers/ata/libata-core.c | 202 +++++++++++++++++++++++++++---------------- drivers/ata/libata-eh.c | 150 +++++++++++++++----------------- drivers/ata/libata-pmp.c | 5 +- drivers/ata/libata-scsi.c | 6 +- drivers/ata/sata_inic162x.c | 2 +- drivers/ata/sata_nv.c | 4 +- include/linux/libata.h | 35 ++++---- 7 files changed, 223 insertions(+), 181 deletions(-)
drivers/ata/libata-core.c +127 -75
@@ -125,6 +125,79 @@ MODULE_LICENSE("GPL");MODULE_VERSION (DRV_VERSION ); +int ata_port_printk (struct ata_port *ap,const char *lv,const char *fmt, ...) +{ +va_list args; +char hbuf[16 ]; +int ret; + +snprintf (hbuf,sizeof (hbuf),"%sata%u: " , lv, ap->print_id); + +va_start (args, fmt); + ret =vprintk_header (hbuf, fmt, args); +va_end (args); + +return ret; +} + +int ata_link_printk (struct ata_link *link,const char *lv,const char *fmt, ...) +{ +va_list args; +char hbuf[16 ]; +int ret; + +if (link->ap->nr_pmp_links) +snprintf (hbuf,sizeof (hbuf),"%sata%u.%02u: " , + lv, link->ap->print_id, link->pmp); +else +snprintf (hbuf,sizeof (hbuf),"%sata%u: " , + lv, link->ap->print_id); + +va_start (args, fmt); + ret =vprintk_header (hbuf, fmt, args); +va_end (args); + +return ret; +} + +int ata_dev_printk (struct ata_device *dev,const char *lv,const char *fmt, ...) +{ +va_list args; +char hbuf[16 ]; +int ret; + +snprintf (hbuf,sizeof (hbuf),"%sata%u.%02u: " , + lv, dev->link->ap->print_id, dev->link->pmp + dev->devno); + +va_start (args, fmt); + ret =vprintk_header (hbuf, fmt, args); +va_end (args); + +return ret; +} + +void ata_port_mp_header (struct ata_port *ap,const char *lv,struct mprintk *mp) +{ +mprintk_set_header (mp,"%sata%u: " , lv, ap->print_id); +} + +void ata_link_mp_header (struct ata_link *link,const char *lv, +struct mprintk *mp) +{ +if (link->ap->nr_pmp_links) +mprintk_set_header (mp,"%sata%u.%02u: " , + lv, link->ap->print_id, link->pmp); +else +mprintk_set_header (mp,"%sata%u: " , lv, link->ap->print_id); +} + +void ata_dev_mp_header (struct ata_device *dev,const char *lv, +struct mprintk *mp) +{ +mprintk_set_header (mp,"%sata%u.%02u: " , lv, dev->link->ap->print_id, + dev->link->pmp + dev->devno); +} +/** * ata_tf_to_fis - Convert ATA taskfile to SATA FIS structure * @tf: Taskfile to convert
@@ -2046,18 +2119,16 @@ static inline u8 ata_dev_knobble(struct ata_device *dev)return ((ap->cbl ==ATA_CBL_SATA ) && (!ata_id_is_sata (dev->id))); } -static void ata_dev_config_ncq (struct ata_device *dev, -char *desc,size_t desc_sz) +static void ata_dev_config_ncq (struct ata_device *dev,struct mprintk *mp) {struct ata_port *ap = dev->link->ap;int hdepth =0 , ddepth =ata_id_queue_depth (dev->id); -if (!ata_id_has_ncq (dev->id)) { - desc[0 ] ='\0' ; +if (!ata_id_has_ncq (dev->id))return ; - } +if (dev->horkage &ATA_HORKAGE_NONCQ ) { -snprintf (desc, desc_sz,"NCQ (not used)" ); +mprintk_add (mp,", NCQ (not used)" );return ; }if (ap->flags &ATA_FLAG_NCQ ) {
@@ -2066,9 +2137,9 @@ static void ata_dev_config_ncq(struct ata_device *dev, }if (hdepth >= ddepth) -snprintf (desc, desc_sz,"NCQ (depth %d)" , ddepth); +mprintk_add (mp,", NCQ (depth %d)" , ddepth);else -snprintf (desc, desc_sz,"NCQ (depth %d/%d)" , hdepth, ddepth); +mprintk_add (mp,", NCQ (depth %d/%d)" , hdepth, ddepth); }/**
@@ -2090,8 +2161,8 @@ int ata_dev_configure(struct ata_device *dev)struct ata_eh_context *ehc = &dev->link->eh_context;int print_info = ehc->i.flags &ATA_EHI_PRINTINFO ;const u16 *id = dev->id; +struct mprintk mp =MPRINTK_INITIALIZER (ap->sector_buf,ATA_SECT_SIZE );unsigned int xfer_mask; -char revbuf[7 ];/* XYZ-99\0 */ char fwrevbuf[ATA_ID_FW_REV_LEN +1 ];char modelbuf[ATA_ID_PROD_LEN +1 ];int rc;
@@ -2105,6 +2176,8 @@ int ata_dev_configure(struct ata_device *dev)if (ata_msg_probe (ap))ata_dev_printk (dev,KERN_DEBUG ,"%s: ENTER\n" , __FUNCTION__); +ata_dev_mp_header (dev,KERN_INFO , &mp); +/* set horkage */ dev->horkage |=ata_dev_blacklisted (dev);
@@ -2153,51 +2226,44 @@ int ata_dev_configure(struct ata_device *dev)ata_id_c_string (dev->id, modelbuf,ATA_ID_PROD ,sizeof (modelbuf)); -/* ATA-specific feature tests */ if (dev->class ==ATA_DEV_ATA ) { +/* ATA-specific feature tests */ if (ata_id_is_cfa (id)) { -if (id[162 ] &1 )/* CPRM may make this media unusable */ +/* CPRM may make this media unusable */ +if ((id[162 ] &1 ) && print_info)ata_dev_printk (dev,KERN_WARNING ,"supports DRM functions and may " "not be fully accessable.\n" ); -snprintf (revbuf,7 ,"CFA" ); +mprintk_add (&mp,"CFA: " ); }else -snprintf (revbuf,7 ,"ATA-%d" ,ata_id_major_version (id)); +mprintk_add (&mp,"ATA-%d: " ,ata_id_major_version (id)); + +mprintk_add (&mp,"%s, %s, max %s\n" , + modelbuf, fwrevbuf,ata_mode_string (xfer_mask)); dev->n_sectors =ata_id_n_sectors (id); +mprintk_add (&mp,"%Lu sectors" , + (unsigned long long )dev->n_sectors); -if (dev->id[59 ] &0x100 ) +if (dev->id[59 ] &0x100 ) { dev->multi_count = dev->id[59 ] &0xff ; +mprintk_add (&mp,", multi %u" , dev->multi_count); + }if (ata_id_has_lba (id)) { -const char *lba_desc; -char ncq_desc[20 ]; - - lba_desc ="LBA" ; dev->flags |=ATA_DFLAG_LBA ; +mprintk_add (&mp,", LBA" ); +if (ata_id_has_lba48 (id)) { dev->flags |=ATA_DFLAG_LBA48 ; - lba_desc ="LBA48" ; - +mprintk_add (&mp,"48" );if (dev->n_sectors >= (1UL <<28 ) &&ata_id_has_flush_ext (id)) dev->flags |=ATA_DFLAG_FLUSH_EXT ; }/* config NCQ */ -ata_dev_config_ncq (dev, ncq_desc,sizeof (ncq_desc)); - -/* print device info to dmesg */ -if (ata_msg_drv (ap) && print_info) { -ata_dev_printk (dev,KERN_INFO , -"%s: %s, %s, max %s\n" , - revbuf, modelbuf, fwrevbuf, -ata_mode_string (xfer_mask)); -ata_dev_printk (dev,KERN_INFO , -"%Lu sectors, multi %u: %s %s\n" , - (unsigned long long )dev->n_sectors, - dev->multi_count, lba_desc, ncq_desc); - } +ata_dev_config_ncq (dev, &mp); }else {/* CHS */
@@ -2213,27 +2279,13 @@ int ata_dev_configure(struct ata_device *dev) dev->sectors = id[56 ]; } -/* print device info to dmesg */ -if (ata_msg_drv (ap) && print_info) { -ata_dev_printk (dev,KERN_INFO , -"%s: %s, %s, max %s\n" , - revbuf, modelbuf, fwrevbuf, -ata_mode_string (xfer_mask)); -ata_dev_printk (dev,KERN_INFO , -"%Lu sectors, multi %u, CHS %u/%u/%u\n" , - (unsigned long long )dev->n_sectors, - dev->multi_count, dev->cylinders, - dev->heads, dev->sectors); - } +mprintk_add (&mp,", CHS %u/%u/%u" , + dev->cylinders, dev->heads, dev->sectors); } dev->cdb_len =16 ; - } - -/* ATAPI-specific feature tests */ -else if (dev->class ==ATA_DEV_ATAPI ) { -const char *cdb_intr_string ="" ; -const char *atapi_an_string ="" ; + }else if (dev->class ==ATA_DEV_ATAPI ) { +/* ATAPI-specific feature tests */ u32 sntf; rc =atapi_cdb_len (id);
@@ -2246,6 +2298,14 @@ int ata_dev_configure(struct ata_device *dev) } dev->cdb_len = (unsigned int ) rc; +mprintk_add (&mp,"ATAPI: %s, %s, max %s" , modelbuf, fwrevbuf, +ata_mode_string (xfer_mask)); + +if (ata_id_cdb_intr (dev->id)) { + dev->flags |=ATA_DFLAG_CDB_INTR ; +mprintk_add (&mp,", CDB intr" ); + } +/* Enable ATAPI AN if both the host and device have * the support. If PMP is attached, SNTF is required * to enable ATAPI AN to discern between PHY status
@@ -2265,22 +2325,9 @@ int ata_dev_configure(struct ata_device *dev) "(err_mask=0x%x)\n", err_mask); else { dev->flags |=ATA_DFLAG_AN ; - atapi_an_string =", ATAPI AN" ; +mprintk_add (&mp,", ATAPI AN" ); } } - -if (ata_id_cdb_intr (dev->id)) { - dev->flags |=ATA_DFLAG_CDB_INTR ; - cdb_intr_string =", CDB intr" ; - } - -/* print device info to dmesg */ -if (ata_msg_drv (ap) && print_info) -ata_dev_printk (dev,KERN_INFO , -"ATAPI: %s, %s, max %s%s%s\n" , - modelbuf, fwrevbuf, -ata_mode_string (xfer_mask), - cdb_intr_string, atapi_an_string); }/* determine max_sectors */
@@ -2295,23 +2342,18 @@ int ata_dev_configure(struct ata_device *dev) dev->flags |=ATA_DFLAG_DIPM ; } -if (dev->horkage &ATA_HORKAGE_DIAGNOSTIC ) { +if ((dev->horkage &ATA_HORKAGE_DIAGNOSTIC ) && print_info) {/* Let the user know. We don't want to disallow opens for rescue purposes, or in case the vendor is just a blithering idiot */ -if (print_info) { -ata_dev_printk (dev,KERN_WARNING , -"Drive reports diagnostics failure. This may indicate a drive\n" ); -ata_dev_printk (dev,KERN_WARNING , -"fault or invalid emulation. Contact drive vendor for information.\n" ); - } +ata_dev_printk (dev,KERN_WARNING , +"Drive reports diagnostics failure. This may indicate a drive\n" +"fault or invalid emulation. Contact drive vendor for information.\n" ); }/* limit bridge transfers to udma5, 200 sectors */ if (ata_dev_knobble (dev)) { -if (ata_msg_drv (ap) && print_info) -ata_dev_printk (dev,KERN_INFO , -"applying bridge limits\n" ); +mprintk_add (&mp,", applying bridge limits" ); dev->udma_mask &=ATA_UDMA5 ; dev->max_sectors =ATA_MAX_SECTORS ; }
@@ -2336,6 +2378,10 @@ int ata_dev_configure(struct ata_device *dev)if (ap->ops->dev_config) ap->ops->dev_config (dev); +/* print device info to dmesg */ +if (ata_msg_drv (ap) && print_info) +mprintk (&mp,"\n" ); +if (ata_msg_probe (ap))ata_dev_printk (dev,KERN_DEBUG ,"%s: EXIT, drv_stat = 0x%x\n" , __FUNCTION__,ata_chk_status (ap));
@@ -7579,6 +7625,12 @@ EXPORT_SYMBOL_GPL(sata_deb_timing_hotplug);EXPORT_SYMBOL_GPL (sata_deb_timing_long);EXPORT_SYMBOL_GPL (ata_dummy_port_ops);EXPORT_SYMBOL_GPL (ata_dummy_port_info); +EXPORT_SYMBOL_GPL (ata_port_printk); +EXPORT_SYMBOL_GPL (ata_link_printk); +EXPORT_SYMBOL_GPL (ata_dev_printk); +EXPORT_SYMBOL_GPL (ata_port_mp_header); +EXPORT_SYMBOL_GPL (ata_link_mp_header); +EXPORT_SYMBOL_GPL (ata_dev_mp_header);EXPORT_SYMBOL_GPL (ata_std_bios_param);EXPORT_SYMBOL_GPL (ata_std_ports);EXPORT_SYMBOL_GPL (ata_host_init);
drivers/ata/libata-eh.c +71 -79
206 lines not on this page · raw message
drivers/ata/libata-pmp.c +2 -3
@@ -408,9 +408,8 @@ static int sata_pmp_configure(struct ata_device *dev, int print_info)if (!(dev->flags &ATA_DFLAG_AN ))ata_dev_printk (dev,KERN_INFO , -"Asynchronous notification not supported, " -"hotplug won't\n work on fan-out " -"ports. Use warm-plug instead.\n" ); +"Asynchronous notification not supported, hotplug won't\n" +"work on fan-out ports. Use warm-plug instead.\n" ); }return 0 ;
drivers/ata/libata-scsi.c +3 -3
@@ -3207,9 +3207,9 @@ void ata_scsi_scan_host(struct ata_port *ap, int sync) goto repeat; } -ata_port_printk (ap,KERN_ERR ,"WARNING: synchronous SCSI scan " -"failed without making any progress,\n" -" switching to async\n" ); +ata_port_printk (ap,KERN_ERR , +"WARNING: synchronous SCSI scan failed without making any \n" +" progress, switching to async\n" ); } queue_delayed_work(ata_aux_wq, &ap->hotplug_task,
drivers/ata/sata_inic162x.c +1 -1
@@ -502,7 +502,7 @@ static void inic_dev_config(struct ata_device *dev)if (dev->n_sectors >=1 <<28 ) {ata_dev_printk (dev,KERN_ERR ,"ERROR: This driver doesn't support LBA48 yet and may cause\n" -" data corruption on such devices. Disabling.\n" ); +" data corruption on such devices. Disabling.\n" );ata_dev_disable (dev); } }
drivers/ata/sata_nv.c +2 -2
@@ -1788,8 +1788,8 @@ static void nv_swncq_ncq_stop(struct ata_port *ap)"EH in SWNCQ mode,QC:qc_active 0x%X sactive 0x%X\n" , ap->qc_active, ap->link.sactive);ata_port_printk (ap,KERN_ERR , -"SWNCQ:qc_active 0x%X defer_bits 0x%X last_issue_tag 0x%x\n " -"dhfis 0x%X dmafis 0x%X sdbfis 0x%X\n" , +"SWNCQ: qc_active 0x%X defer_bits 0x%X last_issue_tag 0x%x\n" +" dhfis 0x%X dmafis 0x%X sdbfis 0x%X\n" , pp->qc_active, pp->defer_queue.defer_bits, pp->last_issue_tag, pp->dhfis_bits, pp->dmafis_bits, pp->sdbfis_bits);
include/linux/libata.h +17 -18
@@ -773,6 +773,23 @@ static inline int ata_port_is_dummy(struct ata_port *ap)return ap->ops == &ata_dummy_port_ops; } +extern int ata_port_printk (struct ata_port *ap,const char *lv, +const char *fmt, ...) + __attribute__ ((format (printf,3 ,4 ))); +extern int ata_link_printk (struct ata_link *link,const char *lv, +const char *fmt, ...) + __attribute__ ((format (printf,3 ,4 ))); +extern int ata_dev_printk (struct ata_device *dev,const char *lv, +const char *fmt, ...) + __attribute__ ((format (printf,3 ,4 ))); + +extern void ata_port_mp_header (struct ata_port *ap,const char *lv, +struct mprintk *mp); +extern void ata_link_mp_header (struct ata_link *link,const char *lv, +struct mprintk *mp); +extern void ata_dev_mp_header (struct ata_device *dev,const char *lv, +struct mprintk *mp); +extern void sata_print_link_status (struct ata_link *link);extern void ata_port_probe (struct ata_port *);extern void ata_bus_reset (struct ata_port *ap);
@@ -1023,24 +1040,6 @@ extern void ata_do_eh(struct ata_port *ap, ata_prereset_fn_t prereset, ata_postreset_fn_t postreset);/* -* printk helpers -*/ -#define ata_port_printk(ap, lv, fmt, args...) \ - printk("%sata%u: "fmt, lv, (ap)->print_id , ##args) - -#define ata_link_printk(link, lv, fmt, args...) do { \ - if ((link)->ap->nr_pmp_links) \ - printk("%sata%u.%02u: "fmt, lv, (link)->ap->print_id, \ - (link)->pmp , ##args); \ - else \ - printk("%sata%u: "fmt, lv, (link)->ap->print_id , ##args); \ - } while(0) - -#define ata_dev_printk(dev, lv, fmt, args...) \ - printk("%sata%u.%02u: "fmt, lv, (dev)->link->ap->print_id, \ - (dev)->link->pmp + (dev)->devno , ##args) - -/* * ata_eh_info helpers */ extern void __ata_ehi_push_desc (struct ata_eh_info *ehi,const char *fmt, ...)
Signature · 1 line
1.5.2.4
Quoted 10 lines · Tejun Heo
In a nutshell,
printk_header()lets you do the following atomically (against other messages).code:
printk(KERN_INFO "ata1.00: ", "line0\nline1\nline2\n");output:
<6>ata1.00: line0
<6> line1
<6> line2
I think this is a really bad idea. It's much better to have:
<6>ata1.00: line0
<6>ata1.00: line1
<6>ata1.00: line2
That way you can grep for ata1.00 and get all messages relevant to that device.
Signature · 4 lines
Intel are signing my paycheques ... these opinions are still mine "Bill, look, we understand that you're interested in selling us this operating system, but compare it to ours. We can't possibly take such a retrograde step."
Quoted 12 lines · Matthew Wilcox
Quoted 10 lines · Tejun Heo
In a nutshell,
printk_header()lets you do the following atomically (against other messages).code:
printk(KERN_INFO "ata1.00: ", "line0\nline1\nline2\n");output:
<6>ata1.00: line0
<6> line1
<6> line2
Quoted 8 lines
I think this is a really bad idea. It's much better to have:
<6>ata1.00: line0
<6>ata1.00: line1
<6>ata1.00: line2That way you can grep for ata1.00 and get all messages relevant to that device.
It has some pros and cons. Having indentation makes things easier on human eyes but more difficult on scripts, but not too difficult - indented lines can easily be matched with a bit of scripting. Changing the behavior is easy but I'm still inclined toward indentation because printing header every line loses information about message boundaries. Maybe there's a way to satisfy both like omitting the separator from the second line on.
ata1.00: line0
ata1.00 line1
ata1.00 line2
Hmm... Any better ideas?
Signature · 1 line
tejun
Quoted 12 lines · Matthew Wilcox
Quoted 10 lines · Tejun Heo
In a nutshell,
printk_header()lets you do the following atomically (against other messages).code:
printk(KERN_INFO "ata1.00: ", "line0\nline1\nline2\n");output:
<6>ata1.00: line0
<6> line1
<6> line2
Quoted 8 lines
I think this is a really bad idea. It's much better to have:
<6>ata1.00: line0
<6>ata1.00: line1
<6>ata1.00: line2That way you can grep for ata1.00 and get all messages relevant to that device.
Agreed, I too prefer <6>ata1.00 on every line.
Quoted 14 lines · Jan Engelhardt
Quoted 13 lines · Matthew Wilcox
Quoted 10 lines · Tejun Heo
In a nutshell,
printk_header()lets you do the following atomically (against other messages).code:
printk(KERN_INFO "ata1.00: ", "line0\nline1\nline2\n");output:
<6>ata1.00: line0
<6> line1
<6> line2I think this is a really bad idea. It's much better to have:
Quoted 8 lines
Quoted 6 lines
<6>ata1.00: line0
<6>ata1.00: line1
<6>ata1.00: line2That way you can grep for ata1.00 and get all messages relevant to that device.
Agreed, I too prefer <6>ata1.00 on every line.
What do you think about the second suggestion then?
ata1.00: line0
ata1.00 line1
ata1.00 line2
It allows you to grab for the header && has indication for message boundaries.
Signature · 1 line
tejun
Quoted 9 lines · Tejun Heo
What do you think about the second suggestion then?
ata1.00: line0
ata1.00 line1
ata1.00 line2It allows you to grab for the header && has indication for message boundaries.
Then again, why not "[ata1.00] line0", then it matches what sd_mod does :)
Quoted 11 lines · Jan Engelhardt
Quoted 8 lines · Tejun Heo
What do you think about the second suggestion then?
ata1.00: line0
ata1.00 line1
ata1.00 line2It allows you to grab for the header && has indication for message boundaries.
Then again, why not "[ata1.00] line0", then it matches what
sd_moddoes :)
Well, that's fine too but using ':' is much more common. Just take a look at the boot log and if we go with '[]', any ideas on how to indicate multiline messages?
Signature · 1 line
tejun