scsi: avoid linebreaks in syslog output
Subsystems (2)
cover scsi: avoid linebreaks in syslog output
This patchset updates the SCSI midlayer to use dev_printk() instead of the simple printk(). The main objective here is to avoid line-breaks in syslog output; with the current state it's nearly impossible to match the output to the occurring device; under high load even the CDB will be split off into individual bytes, spread randomly across the lines. Which makes debugging via scsi_logging_level _really_ hard. In addition we'll be getting the syslog messages nicely prefixed with the device, which will make userspace logging daemons happy.
Before:
[ 297.300605] sd 2:0:3:2: Send: [ 297.300607] 0xffff8802348b0980 [ 297.300610] sd 2:0:3:2: CDB: [ 297.300615] Test Unit Ready: 00 00 00 00 00 00 [ 297.300747] sd 2:0:3:2: Done: [ 297.300750] 0xffff8802348b0980 SUCCESS [ 297.300753] sd 2:0:3:2: [ 297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 297.300758] sd 2:0:3:2: CDB: [ 297.300764] Test Unit Ready: 00 00 00 00 00 00 [ 297.300766] sd 2:0:3:2: [ 297.300769] Sense Key : Unit Attention [current] [ 297.300771] Info fld=0x0 [ 297.300772] sd 2:0:3:2: [ 297.300776] Add. Sense: Capacity data has changed
After:
[ 636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0 [ 636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS [ 636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current] [ 637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changed
Hannes Reinecke (10):
sg: Use dev_printk
sr: Use dev_printk()
scsi: Avoid linebreaks in syslog output
scsi: Use sdev_printk() for logging
scsi: use buffer for print_opcode_name()
scsi: use single printk call in scsi_print_command()
scsi: use buffer for scsi_show_result()
scsi: open-code scsi_decode_sense_buffer()
scsi: decode descriptor sense
scsi: use local buffer for decoding sense data
drivers/scsi/constants.c | 406 +++++++++++++++++++++++++-------------------- drivers/scsi/scsi.c | 54 ++++--- drivers/scsi/scsi_error.c | 190 ++++++++++++++------- drivers/scsi/scsi_lib.c | 13 +- drivers/scsi/scsi_scan.c | 68 ++++---- drivers/scsi/sd.c | 16 +- drivers/scsi/sg.c | 187 ++++++++++++--------- drivers/scsi/sr.c | 47 +++--- drivers/scsi/sr.h | 4 + include/scsi/scsi_dbg.h | 6 +- include/scsi/scsi_eh.h | 8 +- 11 files changed, 588 insertions(+), 411 deletions(-)
Signature · 1 line
1.7.4.2
PATCH 1/10 sg: Use dev_printk
Every sg device has a reference to the underlying scsi device, so this patch adds dev_printk() macros to have the messages prefixed with the correct device.
Before:
[772330.437378] sg_open: dev=2, flags=0x8800 [772330.475425] sg_add_sfp: sfp=0xffff880429d3e000
After:
[ 409.399888] sr 2:0:0:0: [sg2] sg_open: flags=0x8800 [ 409.446029] sr 2:0:0:0: [sg2] sg_add_sfp: sfp=0xffff880425856000
--- drivers/scsi/sg.c | 187 +++++++++++++++++++++++++++++++---------------------- 1 files changed, 109 insertions(+), 78 deletions(-)
drivers/scsi/sg.c +109 -78
@@ -101,6 +101,13 @@ static int scatter_elem_sz_prev = SG_SCATTER_SZ;#define SG_SECTOR_SZ 512 +#define sgdev_printk(prefix, sgdev, fmt, a...) \ + dev_printk(prefix, &(sgdev)->device->sdev_gendev, "[%s] " fmt, \ + (sgdev)->disk->disk_name, ##a) + +#define sgfp_printk(prefix, sgfp, fmt, a...) \ + sgdev_printk(prefix, (sgfp)->parentdp, fmt, ##a) +static int sg_add (struct device *,struct class_interface *);static void sg_remove (struct device *,struct class_interface *);
@@ -196,7 +203,7 @@ static ssize_t sg_new_write(Sg_fd *sfp, struct file *file,static int sg_common_write (Sg_fd * sfp,Sg_request * srp,unsigned char *cmnd,int timeout,int blocking);static int sg_read_oxfer (Sg_request * srp,char __user *outp,int num_read_xfer); -static void sg_remove_scat (Sg_scatter_hold * schp); +static void sg_remove_scat (Sg_scatter_hold * schp,Sg_fd * sfp);static void sg_build_reserve (Sg_fd * sfp,int req_size);static void sg_link_reserve (Sg_fd * sfp,Sg_request * srp,int size);static void sg_unlink_reserve (Sg_fd * sfp,Sg_request * srp);
@@ -268,13 +275,14 @@ sg_open(struct inode *inode, struct file *filp)int retval;nonseekable_open (inode, filp); -SCSI_LOG_TIMEOUT (3 ,printk ("sg_open: dev=%d, flags=0x%x\n" , dev, flags)); sdp =sg_get_dev (dev);if (IS_ERR (sdp)) { retval =PTR_ERR (sdp); sdp =NULL ; goto sg_put; } +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp, +"sg_open: flags=0x%x\n" , flags));/* This driver's module count bumped by fops_get in <linux/fs.h> */ /* Prevent the device driver from vanishing while we sleep */
@@ -360,7 +368,7 @@ sg_release(struct inode *inode, struct file *filp)if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))return -ENXIO ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_release: %s\n" , sdp->disk->disk_name)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_release" ));set_exclude (sdp,0 );wake_up_interruptible (&sdp->o_excl_wait);
@@ -383,8 +391,8 @@ sg_read(struct file *filp, char __user *buf, size_t count, loff_t * ppos)if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))return -ENXIO ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_read: %s, count=%d\n" , - sdp->disk->disk_name, (int ) count)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_read: count=%d" , + (int ) count));if (!access_ok (VERIFY_WRITE , buf, count))return -EFAULT ;
@@ -569,8 +577,8 @@ sg_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))return -ENXIO ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_write: %s, count=%d\n" , - sdp->disk->disk_name, (int ) count)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_write: count=%d" , + (int ) count));if (sdp->detached)return -ENODEV ; if (!((filp->f_flags & O_NONBLOCK) ||
@@ -591,14 +599,17 @@ sg_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)return -EIO ;/* The minimum scsi command length is 6 bytes. */ if (!(srp =sg_add_request (sfp))) { -SCSI_LOG_TIMEOUT (1 ,printk ("sg_write: queue full\n" )); +SCSI_LOG_TIMEOUT (1 ,sgdev_printk (KERN_INFO , sdp, +"sg_write: queue full" ));return -EDOM ; } buf +=SZ_SG_HEADER ;__get_user (opcode, buf);if (sfp->next_cmd_len >0 ) {if (sfp->next_cmd_len >MAX_COMMAND_SIZE ) { -SCSI_LOG_TIMEOUT (1 ,printk ("sg_write: command length too long\n" )); +SCSI_LOG_TIMEOUT (1 ,sgdev_printk (KERN_INFO , sdp, +"sg_write: command " +"length too long\n" )); sfp->next_cmd_len =0 ;sg_remove_request (sfp, srp);return -EIO ;
@@ -610,7 +621,7 @@ sg_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)if ((opcode >=0xc0 ) && old_hdr.twelve_byte) cmd_size =12 ; } -SCSI_LOG_TIMEOUT (4 ,printk ( +SCSI_LOG_TIMEOUT (4 ,sgdev_printk (KERN_INFO , sdp,"sg_write: scsi opcode=0x%02x, cmd_size=%d\n" , (int ) opcode, cmd_size));/* Determine buffer size. */ input_size = count - cmd_size;
@@ -685,7 +696,8 @@ sg_new_write(Sg_fd *sfp, struct file *file, const char __user *buf, sfp->cmd_q =1 ;/* when sg_io_hdr seen, set command queuing on */ if (!(srp =sg_add_request (sfp))) { -SCSI_LOG_TIMEOUT (1 ,printk ("sg_new_write: queue full\n" )); +SCSI_LOG_TIMEOUT (1 ,sgfp_printk (KERN_INFO , sfp, +"sg_new_write: queue full\n" ));return -EDOM ; } srp->sg_io_owned = sg_io_owned;
@@ -754,12 +766,14 @@ sg_common_write(Sg_fd * sfp, Sg_request * srp, hp->host_status =0 ; hp->driver_status =0 ; hp->resid =0 ; -SCSI_LOG_TIMEOUT (4 ,printk ("sg_common_write: scsi opcode=0x%02x, cmd_size=%d\n" , - (int ) cmnd[0 ], (int ) hp->cmd_len)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp, +"sg_common_write: scsi opcode=0x%02x, cmd_size=%d\n" , + (int ) cmnd[0 ], (int ) hp->cmd_len)); k =sg_start_req (srp, cmnd);if (k) { -SCSI_LOG_TIMEOUT (1 ,printk ("sg_common_write: start_req err=%d\n" , k)); +SCSI_LOG_TIMEOUT (1 ,sgfp_printk (KERN_INFO , sfp, +"sg_common_write: start_req err=%d\n" , k));sg_finish_rem_req (srp);return k;/* probably out of space --> ENOMEM */ }
@@ -819,8 +833,8 @@ sg_ioctl(struct file *filp, unsigned int cmd_in, unsigned long arg)if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))return -ENXIO ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_ioctl: %s, cmd=0x%x\n" , - sdp->disk->disk_name, (int ) cmd_in)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_ioctl: cmd=0x%x\n" , + (int ) cmd_in)); read_only = (O_RDWR != (filp->f_flags &O_ACCMODE ));switch (cmd_in) {
@@ -872,7 +886,7 @@ sg_ioctl(struct file *filp, unsigned int cmd_in, unsigned long arg) sfp->low_dma =1 ;if ((0 == sfp->low_dma) && (0 ==sg_res_in_use (sfp))) { val = (int ) sfp->reserve.bufflen; -sg_remove_scat (&sfp->reserve); +sg_remove_scat (&sfp->reserve, sfp);sg_build_reserve (sfp, val); } }else {
@@ -948,7 +962,7 @@ sg_ioctl(struct file *filp, unsigned int cmd_in, unsigned long arg)if (val != sfp->reserve.bufflen) {if (sg_res_in_use (sfp) || sfp->mmap_called)return -EBUSY ; -sg_remove_scat (&sfp->reserve); +sg_remove_scat (&sfp->reserve, sfp);sg_build_reserve (sfp, val); }return 0 ;
@@ -1171,8 +1185,8 @@ sg_poll(struct file *filp, poll_table * wait) res |=POLLOUT |POLLWRNORM ; }else if (count <SG_MAX_QUEUE ) res |=POLLOUT |POLLWRNORM ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_poll: %s, res=0x%x\n" , - sdp->disk->disk_name, (int ) res)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_poll: res=0x%x\n" , + (int ) res));return res; }
@@ -1184,8 +1198,8 @@ sg_fasync(int fd, struct file *filp, int mode)if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))return -ENXIO ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_fasync: %s, mode=%d\n" , - sdp->disk->disk_name, mode)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_fasync: mode=%d" , + mode));return fasync_helper (fd, filp, mode, &sfp->async_qp); }
@@ -1204,8 +1218,9 @@ sg_vma_fault(struct vm_area_struct *vma, struct vm_fault *vmf) offset = vmf->pgoff <<PAGE_SHIFT ;if (offset >= rsv_schp->bufflen)return VM_FAULT_SIGBUS ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_vma_fault: offset=%lu, scatg=%d\n" , - offset, rsv_schp->k_use_sg)); +SCSI_LOG_TIMEOUT (3 ,sgfp_printk (KERN_INFO , sfp, +"sg_vma_fault: offset=%lu, scatg=%d\n" , + offset, rsv_schp->k_use_sg)); sa = vma->vm_start; length =1 << (PAGE_SHIFT + rsv_schp->page_order);for (k =0 ; k < rsv_schp->k_use_sg && sa < vma->vm_end; k++) {
@@ -1240,8 +1255,9 @@ sg_mmap(struct file *filp, struct vm_area_struct *vma)if ((!filp) || (!vma) || (!(sfp = (Sg_fd *) filp->private_data)))return -ENXIO ; req_sz = vma->vm_end - vma->vm_start; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_mmap starting, vm_start=%p, len=%d\n" , - (void *) vma->vm_start, (int ) req_sz)); +SCSI_LOG_TIMEOUT (3 ,sgfp_printk (KERN_INFO , sfp, +"sg_mmap starting, vm_start=%p, len=%d\n" , + (void *) vma->vm_start, (int ) req_sz));if (vma->vm_pgoff)return -EINVAL ;/* want no offset */ rsv_schp = &sfp->reserve;
@@ -1295,14 +1311,15 @@ static void sg_rq_end_io(struct request *rq, int uptodate) sdp = sfp->parentdp;if (unlikely (sdp->detached)) -printk (KERN_INFO "sg_rq_end_io: device detached\n" ); +sgdev_printk (KERN_INFO , sdp,"sg_rq_end_io: device detached" ); sense = rq->sense; result = rq->errors; resid = rq->resid_len; -SCSI_LOG_TIMEOUT (4 ,printk ("sg_cmd_done: %s, pack_id=%d, res=0x%x\n" , - sdp->disk->disk_name, srp->header.pack_id, result)); +SCSI_LOG_TIMEOUT (4 ,sgdev_printk (KERN_INFO , sdp, +"sg_cmd_done: pack_id=%d, res=0x%x" , + srp->header.pack_id, result)); srp->header.resid = resid; ms =jiffies_to_msecs (jiffies); srp->header.duration = (ms > srp->header.duration) ?
@@ -1387,12 +1404,14 @@ static Sg_device *sg_alloc(struct gendisk *disk, struct scsi_device *scsidp) sdp =kzalloc (sizeof (Sg_device),GFP_KERNEL );if (!sdp) { -printk (KERN_WARNING "kmalloc Sg_device failure\n" ); +sdev_printk (KERN_WARNING , scsidp, +"kmalloc Sg_device failure" );return ERR_PTR (-ENOMEM ); }if (!idr_pre_get (&sg_index_idr,GFP_KERNEL )) { -printk (KERN_WARNING "idr expansion Sg_device failure\n" ); +sdev_printk (KERN_WARNING , scsidp, +"idr expansion Sg_device failure" ); error = -ENOMEM ; goto out; }
@@ -1402,19 +1421,20 @@ static Sg_device *sg_alloc(struct gendisk *disk, struct scsi_device *scsidp) error =idr_get_new (&sg_index_idr, sdp, &k);if (error) {write_unlock_irqrestore (&sg_index_lock, iflags); -printk (KERN_WARNING "idr allocation Sg_device failure: %d\n" , - error); +sdev_printk (KERN_WARNING , scsidp, +"idr allocation Sg_device failure: %d\n" , + error); goto out; }if (unlikely (k >=SG_MAX_DEVS )) goto overflow; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_alloc: dev=%d \n" , k));sprintf (disk->disk_name,"sg%d" , k); disk->first_minor = k; sdp->disk = disk; sdp->device = scsidp; +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_alloc" ));INIT_LIST_HEAD (&sdp->sfds);init_waitqueue_head (&sdp->o_excl_wait); sdp->sg_tablesize =queue_max_segments (q);
@@ -1453,7 +1473,7 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf) disk =alloc_disk (1 );if (!disk) { -printk (KERN_WARNING "alloc_disk failed\n" ); +sdev_printk (KERN_WARNING , scsidp,"alloc_disk failed" );return -ENOMEM ; } disk->major =SCSI_GENERIC_MAJOR ;
@@ -1461,7 +1481,7 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf) error = -ENOMEM ; cdev =cdev_alloc ();if (!cdev) { -printk (KERN_WARNING "cdev_alloc failed\n" ); +sdev_printk (KERN_WARNING , scsidp,"cdev_alloc failed" ); goto out; } cdev->owner =THIS_MODULE ;
@@ -1469,7 +1489,7 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf) sdp =sg_alloc (disk, scsidp);if (IS_ERR (sdp)) { -printk (KERN_WARNING "sg_alloc failed\n" ); +sdev_printk (KERN_WARNING , scsidp,"sg_alloc failed" ); error =PTR_ERR (sdp); goto out; }
@@ -1487,18 +1507,19 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf) sdp->index), sdp, "%s", disk->disk_name);if (IS_ERR (sg_class_member)) { -printk (KERN_ERR "sg_add: " -"device_create failed\n" ); +sdev_printk (KERN_ERR , scsidp,"sg_add: " +"device_create failed" ); error =PTR_ERR (sg_class_member); goto cdev_add_err; } error =sysfs_create_link (&scsidp->sdev_gendev.kobj, &sg_class_member->kobj,"generic" );if (error) -printk (KERN_ERR "sg_add: unable to make symlink " -"'generic' back to sg%d\n" , sdp->index); +sdev_printk (KERN_ERR , scsidp, +"sg_add: unable to make symlink " +"'generic' back to sg%d" , sdp->index); }else -printk (KERN_WARNING "sg_add: sg_sys Invalid\n" ); +sdev_printk (KERN_WARNING , scsidp,"sg_add: sg_sys Invalid\n" ); sdev_printk(KERN_NOTICE, scsidp, "Attached scsi generic sg%d type %d\n", sdp->index,
@@ -1535,9 +1556,7 @@ static void sg_device_destroy(struct kref *kref)idr_remove (&sg_index_idr, sdp->index);write_unlock_irqrestore (&sg_index_lock, flags); -SCSI_LOG_TIMEOUT (3 , -printk ("sg_device_destroy: %s\n" , - sdp->disk->disk_name)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_device_destroy" ));put_disk (sdp->disk);kfree (sdp);
@@ -1553,7 +1572,7 @@ static void sg_remove(struct device *cl_dev, struct class_interface *cl_intf)if (!sdp || sdp->detached)return ; -SCSI_LOG_TIMEOUT (3 ,printk ("sg_remove: %s\n" , sdp->disk->disk_name)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp,"sg_remove" ));/* Need a write lock to set sdp->detached. */ write_lock_irqsave (&sg_index_lock, iflags);
@@ -1654,8 +1673,9 @@ static int sg_start_req(Sg_request *srp, unsigned char *cmd)struct rq_map_data *md, map_data;int rw = hp->dxfer_direction ==SG_DXFER_TO_DEV ?WRITE :READ ; -SCSI_LOG_TIMEOUT (4 ,printk (KERN_INFO "sg_start_req: dxfer_len=%d\n" , - dxfer_len)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp, +"sg_start_req: dxfer_len=%d" , + dxfer_len)); rq =blk_get_request (q, rw,GFP_ATOMIC );if (!rq)
@@ -1742,7 +1762,9 @@ static int sg_finish_rem_req(Sg_request * srp)Sg_fd *sfp = srp->parentfp;Sg_scatter_hold *req_schp = &srp->data; -SCSI_LOG_TIMEOUT (4 ,printk ("sg_finish_rem_req: res_used=%d\n" , (int ) srp->res_used)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp, +"sg_finish_rem_req: res_used=%d" , + (int ) srp->res_used));if (srp->rq) {if (srp->bio) ret =blk_rq_unmap_user (srp->bio);
@@ -1753,7 +1775,7 @@ static int sg_finish_rem_req(Sg_request * srp)if (srp->res_used)sg_unlink_reserve (sfp, srp);else -sg_remove_scat (req_schp); +sg_remove_scat (req_schp, sfp);sg_remove_request (sfp, srp);
@@ -1787,8 +1809,9 @@ sg_build_indirect(Sg_scatter_hold * schp, Sg_fd * sfp, int buff_size) ++blk_size;/* don't know why */ /* round request up to next highest SG_SECTOR_SZ byte boundary */ blk_size =ALIGN (blk_size,SG_SECTOR_SZ ); -SCSI_LOG_TIMEOUT (4 ,printk ("sg_build_indirect: buff_size=%d, blk_size=%d\n" , - buff_size, blk_size)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp,"sg_build_indirect: " +"buff_size=%d, blk_size=%d" , + buff_size, blk_size));/* N.B. ret_sz carried into this block ... */ mx_sc_elems =sg_build_sgat (schp, sfp, sg_tablesize);
@@ -1831,14 +1854,16 @@ retry: } } -SCSI_LOG_TIMEOUT (5 ,printk ("sg_build_indirect: k=%d, num=%d, " -"ret_sz=%d\n" , k, num, ret_sz)); +SCSI_LOG_TIMEOUT (5 ,sgfp_printk (KERN_INFO , sfp, +"sg_build_indirect: k=%d, num=%d, " +"ret_sz=%d" , k, num, ret_sz)); }/* end of for loop */ schp->page_order = order; schp->k_use_sg = k; -SCSI_LOG_TIMEOUT (5 ,printk ("sg_build_indirect: k_use_sg=%d, " -"rem_sz=%d\n" , k, rem_sz)); +SCSI_LOG_TIMEOUT (5 ,sgfp_printk (KERN_INFO , sfp, +"sg_build_indirect: k_use_sg=%d, " +"rem_sz=%d" , k, rem_sz)); schp->bufflen = blk_size;if (rem_sz >0 )/* must have failed */
@@ -1855,16 +1880,17 @@ out: }static void -sg_remove_scat (Sg_scatter_hold * schp) +sg_remove_scat (Sg_scatter_hold * schp,Sg_fd * sfp) { -SCSI_LOG_TIMEOUT (4 ,printk ("sg_remove_scat: k_use_sg=%d\n" , schp->k_use_sg)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp, +"sg_remove_scat: k_use_sg=%d" , schp->k_use_sg));if (schp->pages && schp->sglist_len >0 ) {if (!schp->dio_in_use) {int k;for (k =0 ; k < schp->k_use_sg && schp->pages[k]; k++) { -SCSI_LOG_TIMEOUT (5 ,printk ( -"sg_remove_scat: k=%d, pg=0x%p\n" , +SCSI_LOG_TIMEOUT (5 ,sgfp_printk (KERN_INFO , sfp, +"sg_remove_scat: k=%d, pg=0x%p" , k, schp->pages[k]));__free_pages (schp->pages[k], schp->page_order); }
@@ -1881,8 +1907,8 @@ sg_read_oxfer(Sg_request * srp, char __user *outp, int num_read_xfer)Sg_scatter_hold *schp = &srp->data;int k, num; -SCSI_LOG_TIMEOUT (4 ,printk ("sg_read_oxfer: num_read_xfer=%d\n" , - num_read_xfer)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , srp->parentfp, +"sg_read_oxfer: num_read_xfer=%d" , num_read_xfer));if ((!outp) || (num_read_xfer <=0 ))return 0 ;
@@ -1912,14 +1938,15 @@ sg_build_reserve(Sg_fd * sfp, int req_size) {Sg_scatter_hold *schp = &sfp->reserve; -SCSI_LOG_TIMEOUT (4 ,printk ("sg_build_reserve: req_size=%d\n" , req_size)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp, +"sg_build_reserve: req_size=%d" , req_size));do {if (req_size <PAGE_SIZE ) req_size =PAGE_SIZE ;if (0 ==sg_build_indirect (schp, sfp, req_size))return ;else -sg_remove_scat (schp); +sg_remove_scat (schp, sfp); req_size >>=1 ;/* divide by 2 */ }while (req_size > (PAGE_SIZE /2 )); }
@@ -1932,7 +1959,8 @@ sg_link_reserve(Sg_fd * sfp, Sg_request * srp, int size)int k, num, rem; srp->res_used =1 ; -SCSI_LOG_TIMEOUT (4 ,printk ("sg_link_reserve: size=%d\n" , size)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp, +"sg_link_reserve: size=%d" , size)); rem = size; num =1 << (PAGE_SHIFT + rsv_schp->page_order);
@@ -1950,7 +1978,8 @@ sg_link_reserve(Sg_fd * sfp, Sg_request * srp, int size) }if (k >= rsv_schp->k_use_sg) -SCSI_LOG_TIMEOUT (1 ,printk ("sg_link_reserve: BAD size\n" )); +SCSI_LOG_TIMEOUT (1 ,sgfp_printk (KERN_INFO , sfp, +"sg_link_reserve: BAD size" )); } static void
@@ -1958,8 +1987,9 @@ sg_unlink_reserve(Sg_fd * sfp, Sg_request * srp) {Sg_scatter_hold *req_schp = &srp->data; -SCSI_LOG_TIMEOUT (4 ,printk ("sg_unlink_reserve: req->k_use_sg=%d\n" , - (int ) req_schp->k_use_sg)); +SCSI_LOG_TIMEOUT (4 ,sgfp_printk (KERN_INFO , sfp, +"sg_unlink_reserve: req->k_use_sg=%d" , + (int ) req_schp->k_use_sg)); req_schp->k_use_sg =0 ; req_schp->bufflen =0 ; req_schp->pages =NULL ;
@@ -2089,15 +2119,17 @@ sg_add_sfp(Sg_device * sdp, int dev)write_lock_irqsave (&sg_index_lock, iflags);list_add_tail (&sfp->sfd_siblings, &sdp->sfds);write_unlock_irqrestore (&sg_index_lock, iflags); -SCSI_LOG_TIMEOUT (3 ,printk ("sg_add_sfp: sfp=0x%p\n" , sfp)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp, +"sg_add_sfp: sfp=0x%p" , sfp));if (unlikely (sg_big_buff != def_reserved_size)) sg_big_buff = def_reserved_size; bufflen =min_t (int, sg_big_buff,queue_max_sectors (sdp->device->request_queue) *512 );sg_build_reserve (sfp, bufflen); -SCSI_LOG_TIMEOUT (3 ,printk ("sg_add_sfp: bufflen=%d, k_use_sg=%d\n" , - sfp->reserve.bufflen, sfp->reserve.k_use_sg)); +SCSI_LOG_TIMEOUT (3 ,sgdev_printk (KERN_INFO , sdp, +"sg_add_sfp: bufflen=%d, k_use_sg=%d" , + sfp->reserve.bufflen, sfp->reserve.k_use_sg));kref_get (&sdp->d_ref);__module_get (THIS_MODULE );
@@ -2115,16 +2147,15 @@ static void sg_remove_sfp_usercontext(struct work_struct *work)if (sfp->reserve.bufflen >0 ) {SCSI_LOG_TIMEOUT (6 , -printk ("sg_remove_sfp: bufflen=%d, k_use_sg=%d\n" , - (int ) sfp->reserve.bufflen, - (int ) sfp->reserve.k_use_sg)); -sg_remove_scat (&sfp->reserve); +sgdev_printk (KERN_INFO , sdp, +"sg_remove_sfp: bufflen=%d, k_use_sg=%d" , + (int ) sfp->reserve.bufflen, + (int ) sfp->reserve.k_use_sg)); +sg_remove_scat (&sfp->reserve, sfp); }SCSI_LOG_TIMEOUT (6 , -printk ("sg_remove_sfp: %s, sfp=0x%p\n" , - sdp->disk->disk_name, - sfp)); +sgdev_printk (KERN_INFO , sdp,"sg_remove_sfp: sfp=0x%p" , sfp));kfree (sfp);scsi_device_put (sdp->device);
Signature · 1 line
1.7.4.2
Re: [PATCH 01/10] sg: Use dev_printk
Quoted 8 lines · Hannes Reinecke
Every sg device has a reference to the underlying scsi device, so this patch adds
dev_printk()macros to have the messages prefixed with the correct device.Before:
[772330.437378] sg_open: dev=2, flags=0x8800 [772330.475425] sg_add_sfp: sfp=0xffff880429d3e000
Quoted 7 lines
After:
[ 409.399888] sr 2:0:0:0: [sg2] sg_open: flags=0x8800 [ 409.446029] sr 2:0:0:0: [sg2] sg_add_sfp: sfp=0xffff880425856000Cc Kay Sievers <[email protected]>Cc Doug Gilbert <[email protected]>Signed-off-by Hannes Reinecke <[email protected]>
PATCH 2/10 sr: Use dev_printk()
In reply to Hannes ReineckeConvert sr to use dev_printk() to avoid linebreaks in kernel messages.
--- drivers/scsi/sr.c | 47 ++++++++++++++++++++++++++--------------------- drivers/scsi/sr.h | 4 ++++ 2 files changed, 30 insertions(+), 21 deletions(-)
drivers/scsi/sr.c +26 -21
@@ -276,8 +276,8 @@ do_tur:if (!cd->tur_changed) {if (cd->get_event_changed) {if (cd->tur_mismatch++ >8 ) { -sdev_printk (KERN_WARNING , cd->device, -"GET_EVENT and TUR disagree continuously, suppress GET_EVENT events\n" ); +sr_printk (KERN_WARNING , cd, +"GET_EVENT and TUR disagree continuously, suppress GET_EVENT events\n" ); cd->ignore_get_event = true; } }else {
@@ -306,7 +306,7 @@ static int sr_done(struct scsi_cmnd *SCpnt)struct scsi_cd *cd =scsi_cd (SCpnt->request->rq_disk);#ifdef DEBUG -printk ("sr.c done: %x\n" , result); +sr_printk (KERN_INFO , cd,"sr.c done: %x\n" , result);#endif /*
@@ -389,13 +389,16 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)* is used for a killable error condition */ ret =BLKPREP_KILL ; -SCSI_LOG_HLQUEUE (1 ,printk ("Doing sr request, dev = %s, block = %d\n" , - cd->disk->disk_name, block)); +SCSI_LOG_HLQUEUE (1 , +scmd_printk (KERN_INFO , SCpnt, +"Doing sr request, block = %d\n" , block));if (!cd->device || !scsi_device_online (cd->device)) { -SCSI_LOG_HLQUEUE (2 ,printk ("Finishing %u sectors\n" , -blk_rq_sectors (rq))); -SCSI_LOG_HLQUEUE (2 ,printk ("Retry with 0x%p\n" , SCpnt)); +SCSI_LOG_HLQUEUE (2 ,scmd_printk (KERN_INFO , SCpnt, +"Finishing %u sectors\n" , +blk_rq_sectors (rq))); +SCSI_LOG_HLQUEUE (2 ,scmd_printk (KERN_INFO , SCpnt, +"Retry with 0x%p\n" , SCpnt)); goto out; }
@@ -416,7 +419,8 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)if (!in_interrupt ())sr_set_blocklength (cd,2048 );else -printk ("sr: can't switch blocksize: in interrupt\n" ); +scmd_printk (KERN_INFO , SCpnt, +"sr: can't switch blocksize: in interrupt\n" ); }if (s_size !=512 && s_size !=1024 && s_size !=2048 ) {
@@ -429,7 +433,7 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq) goto out; SCpnt->cmnd[0 ] =WRITE_10 ; SCpnt->sc_data_direction =DMA_TO_DEVICE ; - cd->cdi.media_written =1 ; + cd->cdi.media_written =1 ; }else if (rq_data_dir (rq) ==READ ) { SCpnt->cmnd[0 ] =READ_10 ; SCpnt->sc_data_direction =DMA_FROM_DEVICE ;
@@ -447,8 +451,8 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)if (size !=scsi_bufflen (SCpnt)) {scmd_printk (KERN_ERR , SCpnt, -"mismatch count %d, bytes %d\n" , - size,scsi_bufflen (SCpnt)); +"mismatch count %d, bytes %d\n" , + size,scsi_bufflen (SCpnt));if (scsi_bufflen (SCpnt) > size) SCpnt->sdb.length = size; }
@@ -466,11 +470,11 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq) this_count = (scsi_bufflen (SCpnt) >>9 ) / (s_size >>9 ); -SCSI_LOG_HLQUEUE (2 ,printk ("%s : %s %d/%u 512 byte blocks.\n" , - cd->cdi.name, - (rq_data_dir (rq) ==WRITE ) ? -"writing" :"reading" , - this_count,blk_rq_sectors (rq))); +SCSI_LOG_HLQUEUE (2 ,sr_printk (KERN_INFO , cd, +"%s %d/%u 512 byte blocks.\n" , + (rq_data_dir (rq) ==WRITE ) ? +"writing" :"reading" , + this_count,blk_rq_sectors (rq))); SCpnt->cmnd[1 ] =0 ; block = (unsigned int )blk_rq_pos (rq) / (s_size >>9 );
@@ -790,8 +794,9 @@ static void get_sectorsize(struct scsi_cd *cd)case 512 :break ;default : -printk ("%s: unsupported sector size %d.\n" , - cd->cdi.name, sector_size); +sr_printk (KERN_INFO , cd, +"unsupported sector size %d.\n" , + sector_size); cd->capacity =0 ; }
@@ -852,7 +857,7 @@ static void get_capabilities(struct scsi_cd *cd)CDC_SELECT_DISC |CDC_SELECT_SPEED | CDC_MRW | CDC_MRW_W | CDC_RAM);kfree (buffer); -printk ("%s: scsi-1 drive\n" , cd->cdi.name); +sr_printk (KERN_INFO , cd,"scsi-1 drive" );return ; }
@@ -861,7 +866,7 @@ static void get_capabilities(struct scsi_cd *cd) cd->readcd_known =1 ; cd->readcd_cdda = buffer[n +5 ] &0x01 ;/* print some capability bits */ - printk("%s: scsi3-mmc drive: %dx/%dx %s%s%s%s%s%s\n", cd->cdi.name, + sr_printk(KERN_INFO, cd, "scsi3-mmc drive: %dx/%dx %s%s%s%s%s%s", ((buffer[n + 14] << 8) + buffer[n + 15]) / 176, cd->cdi.speed, buffer[n + 3] & 0x01 ? "writer " : "", /* CD Writer */
drivers/scsi/sr.h +4 -0
@@ -55,6 +55,10 @@ typedef struct scsi_cd {struct gendisk *disk; } Scsi_CD; +#define sr_printk(prefix, scd, fmt, a...) \ + sdev_printk(prefix, (scd)->device, "[%s] " fmt, \ + (scd)->cdi.name, ##a) +int sr_do_ioctl (Scsi_CD *,struct packet_command *);int sr_lock_door (struct cdrom_device_info *,int );
Signature · 1 line
1.7.4.2
PATCH 3/10 scsi: Avoid linebreaks in syslog output
In reply to Hannes Reineckesdev_printk() is adding a linebreak automatically, causing the syslog output to be garbled:
[ 542.494393] sr 2:0:0:0: Send: [ 542.494394] 0xffff8804291e5dc0
which will make debuggging painful.
So reshuffle sdev_printk invokation to have it printed on the same line.
--- drivers/scsi/scsi.c | 38 ++++++++++++++++++++++---------------- 1 files changed, 22 insertions(+), 16 deletions(-)
drivers/scsi/scsi.c +22 -16
@@ -551,14 +551,15 @@ void scsi_log_send(struct scsi_cmnd *cmd) level =SCSI_LOG_LEVEL (SCSI_LOG_MLQUEUE_SHIFT ,SCSI_LOG_MLQUEUE_BITS );if (level >1 ) { -scmd_printk (KERN_INFO , cmd,"Send: " );if (level >2 ) -printk ("0x%p " , cmd); -printk ("\n" ); +scmd_printk (KERN_INFO , cmd,"Send: 0x%p" , cmd); +else +scmd_printk (KERN_INFO , cmd,"Send:" );scsi_print_command (cmd);if (level >3 ) { -printk (KERN_INFO "buffer = 0x%p, bufflen = %d," -" queuecommand 0x%p\n" , +scmd_printk (KERN_INFO , cmd, +"buffer = 0x%p, bufflen = %d," +" queuecommand 0x%p" ,scsi_sglist (cmd),scsi_bufflen (cmd), cmd->device->host->hostt->queuecommand);
@@ -588,42 +589,47 @@ void scsi_log_completion(struct scsi_cmnd *cmd, int disposition) SCSI_LOG_MLCOMPLETE_BITS);if (((level >0 ) && (cmd->result || disposition !=SUCCESS )) || (level >1 )) { -scmd_printk (KERN_INFO , cmd,"Done: " ); -if (level >2 ) -printk ("0x%p " , cmd); +const char *disp_str; +/* * Dump truncated values, so we usually fit within * 80 chars. */ switch (disposition) {case SUCCESS : -printk ("SUCCESS\n" ); + disp_str ="SUCCESS" ;break ;case NEEDS_RETRY : -printk ("RETRY\n" ); + disp_str ="RETRY" ;break ;case ADD_TO_MLQUEUE : -printk ("MLQUEUE\n" ); + disp_str ="MLQUEUE" ;break ;case FAILED : -printk ("FAILED\n" ); + disp_str ="FAILED" ;break ;case TIMEOUT_ERROR : -/* +/* * If called via scsi_times_out. */ -printk ("TIMEOUT\n" ); + disp_str ="TIMEOUT" ;break ;default : -printk ("UNKNOWN\n" ); + disp_str ="UNKNOWN" ; } +if (level >2 ) +scmd_printk (KERN_INFO , cmd,"Done: 0x%p %s" , + cmd, disp_str); +else +scmd_printk (KERN_INFO , cmd,"Done: %s" , + disp_str);scsi_print_result (cmd);scsi_print_command (cmd);if (status_byte (cmd->result) &CHECK_CONDITION )scsi_print_sense ("" , cmd);if (level >3 )scmd_printk (KERN_INFO , cmd, -"scsi host busy %d failed %d\n" , +"scsi host busy %d failed %d" , cmd->device->host->host_busy, cmd->device->host->host_failed); }
Signature · 1 line
1.7.4.2
PATCH 4/10 scsi: Use sdev_printk() for logging
In reply to Hannes ReineckeMost scsi logging messages are using a plain printk, making it hard to relate to the originating device.
This patchs moves the scsi logging messages to use sdev_printk() and friends.
--- drivers/scsi/scsi.c | 16 +++-- drivers/scsi/scsi_error.c | 147 ++++++++++++++++++++++++++------------------- drivers/scsi/scsi_lib.c | 13 +++-- drivers/scsi/scsi_scan.c | 68 +++++++++++---------- 4 files changed, 139 insertions(+), 105 deletions(-)
drivers/scsi/scsi.c +10 -6
@@ -691,7 +691,8 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)scsi_queue_insert (cmd,SCSI_MLQUEUE_DEVICE_BUSY ); -SCSI_LOG_MLQUEUE (3 ,printk ("queuecommand : device blocked \n" )); +SCSI_LOG_MLQUEUE (3 ,scmd_printk (KERN_INFO , cmd, +"queuecommand : device blocked" ));/* * NOTE: rtn is still zero here because we don't need the
@@ -739,8 +740,9 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)*/ if (cmd->cmd_len > cmd->device->host->max_cmd_len) {SCSI_LOG_MLQUEUE (3 , -printk ("queuecommand : command too long. " -"cdb_size=%d host->max_cmd_len=%d\n" , +scmd_printk (KERN_INFO , cmd, +"queuecommand : command too long. " +"cdb_size=%d host->max_cmd_len=%d" , cmd->cmd_len, cmd->device->host->max_cmd_len)); cmd->result = (DID_ABORT <<16 );
@@ -766,11 +768,13 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)scsi_queue_insert (cmd, rtn);SCSI_LOG_MLQUEUE (3 , -printk ("queuecommand : request rejected\n" )); +scmd_printk (KERN_INFO , cmd, +"queuecommand : request rejected" )); } out: -SCSI_LOG_MLQUEUE (3 ,printk ("leaving scsi_dispatch_cmnd()\n" )); +SCSI_LOG_MLQUEUE (3 ,scmd_printk (KERN_INFO , cmd, +"leaving scsi_dispatch_cmnd()" ));return rtn; }
@@ -830,7 +834,7 @@ void scsi_finish_command(struct scsi_cmnd *cmd)if (SCSI_SENSE_VALID (cmd)) cmd->result |= (DRIVER_SENSE <<24 ); -SCSI_LOG_MLCOMPLETE (4 ,sdev_printk (KERN_INFO , sdev, +SCSI_LOG_MLCOMPLETE (4 ,scmd_printk (KERN_INFO , cmd,"Notifying upper driver of completion " "(result %x)\n" , cmd->result));
drivers/scsi/scsi_error.c +86 -61
329 lines not on this page · raw message
drivers/scsi/scsi_lib.c +8 -5
@@ -135,7 +135,8 @@ static void __scsi_queue_insert(struct scsi_cmnd *cmd, int reason, int unbusy)unsigned long flags;SCSI_LOG_MLQUEUE (1 , -printk ("Inserting command %p into mlqueue\n" , cmd)); +scmd_printk (KERN_INFO , cmd, +"Inserting command %p into mlqueue" , cmd));/* * Set the appropriate busy bit for the device/host.
@@ -820,8 +821,8 @@ void scsi_io_completion(struct scsi_cmnd *cmd, unsigned int good_bytes)* Next deal with any sectors which we were able to correctly * handle. */ -SCSI_LOG_HLCOMPLETE (1 ,printk ("%u sectors total, " -"%d bytes done.\n" , +SCSI_LOG_HLCOMPLETE (1 ,scmd_printk (KERN_INFO , cmd, +"%u sectors total, %d bytes done." ,blk_rq_sectors (req), good_bytes));/*
@@ -1370,7 +1371,8 @@ static inline int scsi_host_queue_ready(struct request_queue *q,*/ if (--shost->host_blocked ==0 ) {SCSI_LOG_MLQUEUE (3 , -printk ("scsi%d unblocking host at zero depth\n" , +sdev_printk (KERN_INFO , sdev, +"scsi%d unblocking host at zero depth" , shost->host_no)); }else {return 0 ;
@@ -1555,7 +1557,8 @@ static void scsi_request_fn(struct request_queue *q)spin_unlock (q->queue_lock); cmd = req->special;if (unlikely (cmd ==NULL )) { -printk (KERN_CRIT "impossible request in %s.\n" +sdev_printk (KERN_CRIT , sdev, +"impossible request in %s.\n" "please mail a stack trace to " "[email protected]\n" , __func__);
drivers/scsi/scsi_scan.c +35 -33
178 lines not on this page · raw message
Signature · 1 line
1.7.4.2
PATCH 5/10 scsi: use buffer for print_opcode_name()
In reply to Hannes ReineckeInstead of printing directly to syslog print_opcode_name() should be using a private buffer to avoid linebreaks during printout.
--- drivers/scsi/constants.c | 98 +++++++++++++++++++++++++++------------------ 1 files changed, 59 insertions(+), 39 deletions(-)
drivers/scsi/constants.c +59 -39
@@ -204,9 +204,10 @@ static const char * get_sa_name(const struct value_name_pair * arr, }/* attempt to guess cdb length if cdb_len==0 . No trailing linefeed. */ -static void print_opcode_name (unsigned char * cdbp,int cdb_len) +static int print_opcode_name (char *buf,int buf_len, +unsigned char *cdbp,int cdb_len) { -int sa, len, cdb0; +int sa, len, cdb0, sz =0 ;const char * name; cdb0 = cdbp[0 ];
@@ -214,101 +215,119 @@ static void print_opcode_name(unsigned char * cdbp, int cdb_len)case VARIABLE_LENGTH_CMD : len =scsi_varlen_cdb_length (cdbp);if (len <10 ) { -printk ("short variable length command, " -"len=%d ext_len=%d" , len, cdb_len); -break ; + sz =snprintf (buf, buf_len, +"short variable length command, " +"len=%d ext_len=%d" , len, cdb_len); +return sz; } sa = (cdbp[8 ] <<8 ) + cdbp[9 ]; name =get_sa_name (variable_length_arr,VARIABLE_LENGTH_SZ , sa);if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x, sa=0x%x" , + cdb0, sa);if ((cdb_len >0 ) && (len != cdb_len)) -printk (", in_cdb_len=%d, ext_len=%d" , len, cdb_len); + sz =snprintf (buf + sz, buf_len - sz, +", in_cdb_len=%d, ext_len=%d" , + len, cdb_len);break ;case MAINTENANCE_IN : sa = cdbp[1 ] &0x1f ; name =get_sa_name (maint_in_arr,MAINT_IN_SZ , sa);if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x, sa=0x%x" , + cdb0, sa);break ;case MAINTENANCE_OUT : sa = cdbp[1 ] &0x1f ; name =get_sa_name (maint_out_arr,MAINT_OUT_SZ , sa);if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x, sa=0x%x" , + cdb0, sa);break ;case SERVICE_ACTION_IN_12 : sa = cdbp[1 ] &0x1f ; name =get_sa_name (serv_in12_arr,SERV_IN12_SZ , sa);if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x, sa=0x%x" , + cdb0, sa);break ;case SERVICE_ACTION_OUT_12 : sa = cdbp[1 ] &0x1f ; name =get_sa_name (serv_out12_arr,SERV_OUT12_SZ , sa);if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x, sa=0x%x" , + cdb0, sa);break ;case SERVICE_ACTION_IN_16 : sa = cdbp[1 ] &0x1f ; name =get_sa_name (serv_in16_arr,SERV_IN16_SZ , sa);if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x, sa=0x%x" , + cdb0, sa);break ;case SERVICE_ACTION_OUT_16 : sa = cdbp[1 ] &0x1f ; name =get_sa_name (serv_out16_arr,SERV_OUT16_SZ , sa);if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x, sa=0x%x" , + cdb0, sa);break ;default :if (cdb0 <0xc0 ) { name = cdb_byte0_names[cdb0];if (name) -printk ("%s" , name); + sz =snprintf (buf, buf_len,"%s" , name);else -printk ("cdb[0]=0x%x (reserved)" , cdb0); + sz =snprintf (buf, buf_len, +"cdb[0]=0x%x (reserved)" , cdb0); }else -printk ("cdb[0]=0x%x (vendor)" , cdb0); + sz =snprintf (buf, buf_len,"cdb[0]=0x%x (vendor)" , + cdb0); break; } +return sz; }#else /* ifndef CONFIG_SCSI_CONSTANTS */ -static void print_opcode_name (unsigned char * cdbp,int cdb_len) +static int print_opcode_name (char *buf,int buf_len, +unsigned char *cdbp,int cdb_len) { -int sa, len, cdb0; +int sa, len, cdb0, sz =0 ; cdb0 = cdbp[0 ]; + sz =snprintf (buf, buf_len,"cdb[0]=0x%x" , cdb0);switch (cdb0) {case VARIABLE_LENGTH_CMD : len =scsi_varlen_cdb_length (cdbp);if (len <10 ) { -printk ("short opcode=0x%x command, len=%d " -"ext_len=%d" , cdb0, len, cdb_len); + sz +=snprintf (buf + sz, buf_size - sz, +"short command, len=%d ext_len=%d" , + len, cdb_len);break ; } sa = (cdbp[8 ] <<8 ) + cdbp[9 ]; -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz +=snprintf (buf + sz, buf_len - sz,", sa=0x%x" , sa);if (len != cdb_len) -printk (", in_cdb_len=%d, ext_len=%d" , len, cdb_len); + sz +=snprintf (buf + sz, buf_len - sz, +", in_cdb_len=%d, ext_len=%d" , + len, cdb_len);break ;case MAINTENANCE_IN :case MAINTENANCE_OUT :
@@ -317,23 +336,24 @@ static void print_opcode_name(unsigned char * cdbp, int cdb_len)case SERVICE_ACTION_IN_16 :case SERVICE_ACTION_OUT_16 : sa = cdbp[1 ] &0x1f ; -printk ("cdb[0]=0x%x, sa=0x%x" , cdb0, sa); + sz +=snprintf (buf + sz, buf_len - sz,", sa=0x%x" , sa);break ;default : -if (cdb0 <0xc0 ) -printk ("cdb[0]=0x%x" , cdb0); -else -printk ("cdb[0]=0x%x (vendor)" , cdb0); +if (cdb0 >=0xc0 ) + sz +=snprintf (buf + sz, buf_len - sz," (vendor)" ); break; } +return sz; } -#endif +#endif void __scsi_print_command (unsigned char *cdb) {int k, len; +char cdb_str[64 ]; -print_opcode_name (cdb,0 ); +print_opcode_name (cdb_str,64 , cdb,0 ); +pr_info ("%s" , cdb_str); len =scsi_command_size (cdb);/* print out all bytes in cdb */ for (k =0 ; k < len; ++k)
@@ -345,15 +365,15 @@ EXPORT_SYMBOL(__scsi_print_command);void scsi_print_command (struct scsi_cmnd *cmd) {int k; +char cdb_str[64 ];if (cmd->cmnd ==NULL )return ; -scmd_printk (KERN_INFO , cmd,"CDB: " ); -print_opcode_name (cmd->cmnd, cmd->cmd_len); +print_opcode_name (cdb_str,64 , cmd->cmnd, cmd->cmd_len); +scmd_printk (KERN_INFO , cmd,"CDB: %s:" , cdb_str);/* print out all bytes in cdb */ -printk (":" );for (k =0 ; k < cmd->cmd_len; ++k)printk (" %02x" , cmd->cmnd[k]);printk ("\n" );
Signature · 1 line
1.7.4.2
PATCH 6/10 scsi: use single printk call in scsi_print_command()
In reply to Hannes Reineckescsi_print_command is using several calls to printk(), causing the output to be garbled. Modify it to use a single call to printk().
--- drivers/scsi/constants.c | 71 +++++++++++++++++++++++++++++++++++++++------ 1 files changed, 61 insertions(+), 10 deletions(-)
drivers/scsi/constants.c +61 -10
@@ -349,34 +349,85 @@ static int print_opcode_name(char *buf, int buf_len,void __scsi_print_command (unsigned char *cdb) { -int k, len; +int k, len, rem, linelen;char cdb_str[64 ]; +char line[16 *3 +1 ];print_opcode_name (cdb_str,64 , cdb,0 ); -pr_info ("%s" , cdb_str); len =scsi_command_size (cdb);/* print out all bytes in cdb */ -for (k =0 ; k < len; ++k) -printk (" %02x" , cdb[k]); -printk ("\n" ); +switch (len) { +case 6 : +pr_info ("%s %6ph\n" , cdb_str, cdb); +break ; +case 10 : +pr_info ("%s %10ph\n" , cdb_str, cdb); +break ; +case 12 : +pr_info ("%s %12ph\n" , cdb_str, cdb); +break ; +case 16 : +pr_info ("%s %16ph\n" , cdb_str, cdb); +break ; +default : +pr_info ("%s\n" , cdb_str); + rem = len; +for (k =0 ; k < len; k +=16 ) { + linelen =min (rem,16 ); + rem -=16 ; + +hex_dump_to_buffer (cdb + k, linelen,16 ,1 , + line,sizeof (line), false); +pr_info ("%s\n" , line); + } +break ; + } }EXPORT_SYMBOL (__scsi_print_command);void scsi_print_command (struct scsi_cmnd *cmd) { -int k; +int k, rem, linelen;char cdb_str[64 ]; +char line[16 *3 +1 ];if (cmd->cmnd ==NULL )return ;print_opcode_name (cdb_str,64 , cmd->cmnd, cmd->cmd_len); -scmd_printk (KERN_INFO , cmd,"CDB: %s:" , cdb_str);/* print out all bytes in cdb */ -for (k =0 ; k < cmd->cmd_len; ++k) -printk (" %02x" , cmd->cmnd[k]); -printk ("\n" ); +switch (cmd->cmd_len) { +case 6 : +scmd_printk (KERN_INFO , cmd,"CDB: %s: %6ph\n" , + cdb_str, cmd->cmnd); +break ; +case 10 : +scmd_printk (KERN_INFO , cmd,"CDB: %s: %10ph\n" , + cdb_str, cmd->cmnd); +break ; +case 12 : +scmd_printk (KERN_INFO , cmd,"CDB: %s: %12ph\n" , + cdb_str, cmd->cmnd); +break ; +case 16 : +scmd_printk (KERN_INFO , cmd,"CDB: %s: %16ph\n" , + cdb_str, cmd->cmnd); +break ; +default : +scmd_printk (KERN_INFO , cmd,"CDB: %s\n" , cdb_str); + rem = cmd->cmd_len; +for (k =0 ; k < cmd->cmd_len; k +=16 ) { + linelen =min (rem,16 ); + rem -=16 ; + +hex_dump_to_buffer (cmd->cmnd + k, linelen,16 ,1 , + line,sizeof (line), false); +scmd_printk (KERN_INFO , cmd," %d: %s\n" , + k, line); + } +break ; + } }EXPORT_SYMBOL (scsi_print_command);
Signature · 1 line
1.7.4.2
PATCH 7/10 scsi: use buffer for scsi_show_result()
In reply to Hannes Reineckescsi_show_result() should be printing the message into a supplied buffer to avoid linebreaks during output.
--- drivers/scsi/constants.c | 23 +++++++++++++---------- drivers/scsi/sd.c | 6 ++++-- include/scsi/scsi_dbg.h | 2 +- 3 files changed, 18 insertions(+), 13 deletions(-)
drivers/scsi/constants.c +13 -10
@@ -1502,32 +1502,35 @@ static const char * const driverbyte_table[]={ "DRIVER_INVALID", "DRIVER_TIMEOUT", "DRIVER_HARD", "DRIVER_SENSE"};#define NUM_DRIVERBYTE_STRS ARRAY_SIZE(driverbyte_table) -void scsi_show_result (int result) +void scsi_show_result (char *buf,int buf_size,int result) {int hb =host_byte (result);int db =driver_byte (result); -printk ("Result: hostbyte=%s driverbyte=%s\n" , - (hb <NUM_HOSTBYTE_STRS ? hostbyte_table[hb] :"invalid" ), - (db <NUM_DRIVERBYTE_STRS ? driverbyte_table[db] :"invalid" )); +snprintf (buf, buf_size, +"Result: hostbyte=%s driverbyte=%s\n" , + (hb <NUM_HOSTBYTE_STRS ? hostbyte_table[hb] :"invalid" ), + (db <NUM_DRIVERBYTE_STRS ? driverbyte_table[db] :"invalid" )); }#else -void scsi_show_result (int result) +void scsi_show_result (char *buf,int buf_size,int result) { -printk ("Result: hostbyte=0x%02x driverbyte=0x%02x\n" , -host_byte (result),driver_byte (result)); +snprintf (buf, buf_size, +"Result: hostbyte=0x%02x driverbyte=0x%02x\n" , +host_byte (result),driver_byte (result)); }#endif EXPORT_SYMBOL (scsi_show_result); -void scsi_print_result (struct scsi_cmnd *cmd) { -scmd_printk (KERN_INFO , cmd," " ); -scsi_show_result (cmd->result); +char result_buf[70 ]; + +scsi_show_result (result_buf,70 , cmd->result); +scmd_printk (KERN_INFO , cmd,"%s" , result_buf); }EXPORT_SYMBOL (scsi_print_result);
drivers/scsi/sd.c +4 -2
@@ -3025,7 +3025,9 @@ static void sd_print_sense_hdr(struct scsi_disk *sdkp,static void sd_print_result (struct scsi_disk *sdkp,int result) { -sd_printk (KERN_INFO , sdkp," " ); -scsi_show_result (result); +char result_buf[70 ]; + +scsi_show_result (result_buf,70 , result); +sd_printk (KERN_INFO , sdkp,"%s" , result_buf); }
include/scsi/scsi_dbg.h +1 -1
@@ -15,7 +15,7 @@ extern void scsi_print_sense(char *, struct scsi_cmnd *);extern void __scsi_print_sense (const char *name,const unsigned char *sense_buffer,int sense_len); -extern void scsi_show_result (int ); +extern void scsi_show_result (char *,int ,int );extern void scsi_print_result (struct scsi_cmnd *);extern void scsi_print_status (unsigned char );extern const char *scsi_sense_key_string (unsigned char );
Signature · 1 line
1.7.4.2
PATCH 8/10 scsi: open-code scsi_decode_sense_buffer()
In reply to Hannes ReineckePointless, and actually wrong as there is no point in trying to decode invalid sense data.
--- drivers/scsi/constants.c | 43 +++++++++++++++++-------------------------- 1 files changed, 17 insertions(+), 26 deletions(-)
drivers/scsi/constants.c +17 -26
@@ -1373,29 +1373,6 @@ scsi_cmd_print_sense_hdr(struct scsi_cmnd *scmd, const char *desc,EXPORT_SYMBOL (scsi_cmd_print_sense_hdr);static void -scsi_decode_sense_buffer (const unsigned char *sense_buffer,int sense_len, -struct scsi_sense_hdr *sshdr) -{ -int k, num, res; - - res =scsi_normalize_sense (sense_buffer, sense_len, sshdr); -if (0 == res) { -/* this may be SCSI-1 sense data */ - num = (sense_len <32 ) ? sense_len :32 ; -printk ("Unrecognized sense data (in hex):" ); -for (k =0 ; k < num; ++k) { -if (0 == (k %16 )) { -printk ("\n" ); -printk (KERN_INFO " " ); - } -printk ("%02x " , sense_buffer[k]); - } -printk ("\n" ); -return ; - } -} - -static void scsi_decode_sense_extras (const unsigned char *sense_buffer,int sense_len,struct scsi_sense_hdr *sshdr) {
@@ -1462,8 +1439,15 @@ void __scsi_print_sense(const char *name, const unsigned char *sense_buffer, {struct scsi_sense_hdr sshdr; +if (!scsi_normalize_sense (sense_buffer, sense_len, &sshdr)) { +/* this may be SCSI-1 sense data */ +int num = (sense_len <32 ) ? sense_len :32 ; +pr_info ("%s: Unrecognized sense data (in hex):" , name); +print_hex_dump (KERN_INFO ," " ,DUMP_PREFIX_OFFSET , +16 ,1 , sense_buffer, num, false); +return ; + }printk (KERN_INFO "%s: " , name); -scsi_decode_sense_buffer (sense_buffer, sense_len, &sshdr);scsi_show_sense_hdr (&sshdr);scsi_decode_sense_extras (sense_buffer, sense_len, &sshdr);printk (KERN_INFO "%s: " , name);
@@ -1476,9 +1460,16 @@ void scsi_print_sense(char *name, struct scsi_cmnd *cmd) {struct scsi_sense_hdr sshdr; +if (!scsi_normalize_sense (cmd->sense_buffer,SCSI_SENSE_BUFFERSIZE , + &sshdr)) { +scmd_printk (KERN_INFO , cmd, +"Unrecognized sense data (in hex):" ); +print_hex_dump (KERN_INFO ," " ,DUMP_PREFIX_OFFSET , +16 ,1 , cmd->sense_buffer,SCSI_SENSE_BUFFERSIZE , + false); +return ; + }scmd_printk (KERN_INFO , cmd," " ); -scsi_decode_sense_buffer (cmd->sense_buffer,SCSI_SENSE_BUFFERSIZE , - &sshdr);scsi_show_sense_hdr (&sshdr);scsi_decode_sense_extras (cmd->sense_buffer,SCSI_SENSE_BUFFERSIZE , &sshdr);
Signature · 1 line
1.7.4.2
PATCH 9/10 scsi: decode descriptor sense
In reply to Hannes ReineckeDecode descriptor sense buffer to provide the same information as we are already getting from fixed format sense.
--- drivers/scsi/constants.c | 79 +++++++++++++++------------------------------ drivers/scsi/scsi_error.c | 43 +++++++++++++++++++++++- include/scsi/scsi_eh.h | 8 +++- 3 files changed, 73 insertions(+), 57 deletions(-)
drivers/scsi/constants.c +26 -53
@@ -1376,61 +1376,34 @@ static void scsi_decode_sense_extras(const unsigned char *sense_buffer, int sense_len, struct scsi_sense_hdr *sshdr) { - int k, num, res; - -if (sshdr->response_code <0x72 ) - { -/* only decode extras for "fixed" format now */ -char buff[80 ]; -int blen, fixed_valid; -unsigned int info; - - fixed_valid = sense_buffer[0 ] &0x80 ; - info = ((sense_buffer[3 ] <<24 ) | (sense_buffer[4 ] <<16 ) | - (sense_buffer[5 ] <<8 ) | sense_buffer[6 ]); - res =0 ; -memset (buff,0 ,sizeof (buff)); - blen =sizeof (buff) -1 ; -if (fixed_valid) - res +=snprintf (buff + res, blen - res, -"Info fld=0x%x" , info); -if (sense_buffer[2 ] &0x80 ) { -/* current command has read a filemark */ -if (res >0 ) - res +=snprintf (buff + res, blen - res,", " ); - res +=snprintf (buff + res, blen - res,"FMK" ); - } -if (sense_buffer[2 ] &0x40 ) { -/* end-of-medium condition exists */ -if (res >0 ) - res +=snprintf (buff + res, blen - res,", " ); - res +=snprintf (buff + res, blen - res,"EOM" ); - } -if (sense_buffer[2 ] &0x20 ) { -/* incorrect block length requested */ -if (res >0 ) - res +=snprintf (buff + res, blen - res,", " ); - res +=snprintf (buff + res, blen - res,"ILI" ); - } -if (res >0 ) -printk ("%s\n" , buff); - }else if (sshdr->additional_length >0 ) { -/* descriptor format with sense descriptors */ - num =8 + sshdr->additional_length; - num = (sense_len < num) ? sense_len : num; -printk ("Descriptor sense data with sense descriptors " -"(in hex):" ); -for (k =0 ; k < num; ++k) { -if (0 == (k %16 )) { -printk ("\n" ); -printk (KERN_INFO " " ); - } -printk ("%02x " , sense_buffer[k]); - } + int res = 0; +char buff[80 ]; +int blen = sense_len; -printk ("\n" ); - } +if (sshdr->info) + res +=snprintf (buff + res, blen - res, +"Info fld=0x%llx" , sshdr->info); +if (sshdr->flags &SCSI_SENSE_FLAG_FMK ) { +/* current command has read a filemark */ +if (res >0 ) + res +=snprintf (buff + res, blen - res,", " ); + res +=snprintf (buff + res, blen - res,"FMK" ); + } +if (sshdr->flags &SCSI_SENSE_FLAG_EOM ) { +/* end-of-medium condition exists */ +if (res >0 ) + res +=snprintf (buff + res, blen - res,", " ); + res +=snprintf (buff + res, blen - res,"EOM" ); + } +if (sshdr->flags &SCSI_SENSE_FLAG_ILI ) { +/* incorrect block length requested */ +if (res >0 ) + res +=snprintf (buff + res, blen - res,", " ); + res +=snprintf (buff + res, blen - res,"ILI" ); + } +if (res >0 ) +pr_info ("%s\n" , buff); }/* Normalize and print sense buffer with name prefix */
drivers/scsi/scsi_error.c +41 -2
73 lines not on this page · raw message
include/scsi/scsi_eh.h +6 -2
@@ -21,10 +21,14 @@ struct scsi_sense_hdr { /* See SPC-3 section 4.5 */u8 sense_key;u8 asc;u8 ascq; -u8 byte4; -u8 byte5; +u8 flags; +#define SCSI_SENSE_FLAG_FMK 0x8 +#define SCSI_SENSE_FLAG_EOM 0x4 +#define SCSI_SENSE_FLAG_ILI 0x2 +u8 fru;u8 byte6;u8 additional_length;/* always 0 for fixed sense format */ +u64 info; };static inline int scsi_sense_valid (struct scsi_sense_hdr *sshdr)
Signature · 1 line
1.7.4.2
PATCH 10/10 scsi: use local buffer for decoding sense data
In reply to Hannes ReineckeInstead of printing directly to console we should be using a local buffer for formatting sense data.
This will avoid garbled output.
--- drivers/scsi/constants.c | 102 +++++++++++++++++++++++++-------------------- drivers/scsi/sd.c | 10 +++-- include/scsi/scsi_dbg.h | 4 +- 3 files changed, 65 insertions(+), 51 deletions(-)
drivers/scsi/constants.c +57 -45
@@ -1299,49 +1299,52 @@ scsi_extd_sense_format(unsigned char asc, unsigned char ascq) {EXPORT_SYMBOL (scsi_extd_sense_format);void -scsi_show_extd_sense (unsigned char asc,unsigned char ascq) +scsi_show_extd_sense (char *buf,int buf_len, +unsigned char asc,unsigned char ascq) { -const char *extd_sense_fmt =scsi_extd_sense_format (asc, ascq); +const char *extd_sense_fmt =scsi_extd_sense_format (asc, ascq); +int sz =0 ;if (extd_sense_fmt) {if (strstr (extd_sense_fmt,"%x" )) { -printk ("Add. Sense: " ); -printk (extd_sense_fmt, ascq); + sz =snprintf (buf, buf_len,"Add. Sense: " ); + sz +=snprintf (buf + sz, buf_len - sz, + extd_sense_fmt, ascq); }else -printk ("Add. Sense: %s" , extd_sense_fmt); + sz =snprintf (buf, buf_len,"Add. Sense: %s" , + extd_sense_fmt); }else {if (asc >=0x80 ) -printk ("<<vendor>> ASC=0x%x ASCQ=0x%x" , asc, - ascq); -if (ascq >=0x80 ) -printk ("ASC=0x%x <<vendor>> ASCQ=0x%x" , asc, - ascq); +snprintf (buf, buf_len,"<<vendor>> ASC=0x%x ASCQ=0x%x" , + asc, ascq); +else if (ascq >=0x80 ) +snprintf (buf, buf_len,"ASC=0x%x <<vendor>> ASCQ=0x%x" , + asc, ascq);else -printk ("ASC=0x%x ASCQ=0x%x" , asc, ascq); +snprintf (buf, buf_len,"ASC=0x%x ASCQ=0x%x" , asc, ascq); } - -printk ("\n" ); }EXPORT_SYMBOL (scsi_show_extd_sense);void -scsi_show_sense_hdr (struct scsi_sense_hdr *sshdr) +scsi_show_sense_hdr (char *buf,int buf_len,struct scsi_sense_hdr *sshdr) {const char *sense_txt; +int sz; sense_txt =scsi_sense_key_string (sshdr->sense_key);if (sense_txt) -printk ("Sense Key : %s " , sense_txt); + sz =snprintf (buf, buf_len,"Sense Key : %s " , sense_txt);else -printk ("Sense Key : 0x%x " , sshdr->sense_key); + sz =snprintf (buf, buf_len,"Sense Key : 0x%x " , + sshdr->sense_key); -printk ("%s" ,scsi_sense_is_deferred (sshdr) ?"[deferred] " : -"[current] " ); + sz +=snprintf (buf + sz, buf_len - sz,"%s" , +scsi_sense_is_deferred (sshdr) ? +"[deferred] " :"[current] " );if (sshdr->response_code >=0x72 ) -printk ("[descriptor]" ); - -printk ("\n" ); + sz +=snprintf (buf + sz, buf_len - sz,"[descriptor]" ); }EXPORT_SYMBOL (scsi_show_sense_hdr);
@@ -1351,10 +1354,12 @@ EXPORT_SYMBOL(scsi_show_sense_hdr);void scsi_print_sense_hdr (const char *name,struct scsi_sense_hdr *sshdr) { -printk (KERN_INFO "%s: " , name); -scsi_show_sense_hdr (sshdr); -printk (KERN_INFO "%s: " , name); -scsi_show_extd_sense (sshdr->asc, sshdr->ascq); +char sense_buf[128 ]; + +scsi_show_sense_hdr (sense_buf,128 , sshdr); +pr_info ("%s: %s" , name, sense_buf); +scsi_show_extd_sense (sense_buf,128 , sshdr->asc, sshdr->ascq); +pr_info ("%s: %s" , name, sense_buf); }EXPORT_SYMBOL (scsi_print_sense_hdr);
@@ -1365,20 +1370,21 @@ void scsi_cmd_print_sense_hdr(struct scsi_cmnd *scmd, const char *desc, struct scsi_sense_hdr *sshdr) { - scmd_printk(KERN_INFO, scmd, "%s: ", desc); -scsi_show_sense_hdr (sshdr); -scmd_printk (KERN_INFO , scmd,"%s: " , desc); -scsi_show_extd_sense (sshdr->asc, sshdr->ascq); + char sense_buf[128]; + +scsi_show_sense_hdr (sense_buf,128 , sshdr); +scmd_printk (KERN_INFO , scmd,"%s: %s" , desc, sense_buf); +scsi_show_extd_sense (sense_buf,128 , sshdr->asc, sshdr->ascq); +scmd_printk (KERN_INFO , scmd,"%s: %s" , desc, sense_buf); }EXPORT_SYMBOL (scsi_cmd_print_sense_hdr); -static void -scsi_decode_sense_extras (const unsigned char *sense_buffer,int sense_len, +static int +scsi_decode_sense_extras (char *buff,int buff_len,struct scsi_sense_hdr *sshdr) {int res =0 ; -char buff[80 ]; -int blen = sense_len; +int blen = buff_len;if (sshdr->info) res += snprintf(buff + res, blen - res,
@@ -1402,8 +1408,7 @@ scsi_decode_sense_extras(const unsigned char *sense_buffer, int sense_len, res +=snprintf (buff + res, blen - res,", " ); res +=snprintf (buff + res, blen - res,"ILI" ); } -if (res >0 ) -pr_info ("%s\n" , buff); +return res; }/* Normalize and print sense buffer with name prefix */
@@ -1411,6 +1416,8 @@ void __scsi_print_sense(const char *name, const unsigned char *sense_buffer, int sense_len) {struct scsi_sense_hdr sshdr; +char sense_buf[128 ]; +int len;if (!scsi_normalize_sense (sense_buffer, sense_len, &sshdr)) {/* this may be SCSI-1 sense data */
@@ -1420,11 +1427,13 @@ void __scsi_print_sense(const char *name, const unsigned char *sense_buffer, 16, 1, sense_buffer, num, false);return ; } +scsi_show_sense_hdr (sense_buf,128 , &sshdr); +pr_info ("%s: %s" , name, sense_buf); + len =scsi_decode_sense_extras (sense_buf,128 , &sshdr); +if (len) +pr_info ("%s: %s" , name, sense_buf); +scsi_show_extd_sense (sense_buf,128 , sshdr.asc, sshdr.ascq);printk (KERN_INFO "%s: " , name); -scsi_show_sense_hdr (&sshdr); -scsi_decode_sense_extras (sense_buffer, sense_len, &sshdr); -printk (KERN_INFO "%s: " , name); -scsi_show_extd_sense (sshdr.asc, sshdr.ascq); }EXPORT_SYMBOL (__scsi_print_sense);
@@ -1432,6 +1441,8 @@ EXPORT_SYMBOL(__scsi_print_sense);void scsi_print_sense (char *name,struct scsi_cmnd *cmd) {struct scsi_sense_hdr sshdr; +char sense_buf[128 ]; +int len;if (!scsi_normalize_sense (cmd->sense_buffer,SCSI_SENSE_BUFFERSIZE , &sshdr)) {
@@ -1442,12 +1453,13 @@ void scsi_print_sense(char *name, struct scsi_cmnd *cmd) false);return ; } -scmd_printk (KERN_INFO , cmd," " ); -scsi_show_sense_hdr (&sshdr); -scsi_decode_sense_extras (cmd->sense_buffer,SCSI_SENSE_BUFFERSIZE , - &sshdr); -scmd_printk (KERN_INFO , cmd," " ); -scsi_show_extd_sense (sshdr.asc, sshdr.ascq); +scsi_show_sense_hdr (sense_buf,128 , &sshdr); +scmd_printk (KERN_INFO , cmd,"%s" , sense_buf); + len =scsi_decode_sense_extras (sense_buf,128 , &sshdr); +if (len) +scmd_printk (KERN_INFO , cmd,"%s" , sense_buf); +scsi_show_extd_sense (sense_buf,128 , sshdr.asc, sshdr.ascq); +scmd_printk (KERN_INFO , cmd,"%s" , sense_buf); }EXPORT_SYMBOL (scsi_print_sense);
drivers/scsi/sd.c +6 -4
@@ -3017,10 +3017,12 @@ module_exit(exit_sd);static void sd_print_sense_hdr (struct scsi_disk *sdkp,struct scsi_sense_hdr *sshdr) { -sd_printk (KERN_INFO , sdkp," " ); -scsi_show_sense_hdr (sshdr); -sd_printk (KERN_INFO , sdkp," " ); -scsi_show_extd_sense (sshdr->asc, sshdr->ascq); +char sense_buf[128 ]; + +scsi_show_sense_hdr (sense_buf,128 , sshdr); +sd_printk (KERN_INFO , sdkp,"%s" , sense_buf); +scsi_show_extd_sense (sense_buf,128 , sshdr->asc, sshdr->ascq); +sd_printk (KERN_INFO , sdkp,"%s" , sense_buf); }static void sd_print_result (struct scsi_disk *sdkp,int result)
include/scsi/scsi_dbg.h +2 -2
@@ -6,8 +6,8 @@ struct scsi_sense_hdr;extern void scsi_print_command (struct scsi_cmnd *);extern void __scsi_print_command (unsigned char *); -extern void scsi_show_extd_sense (unsigned char ,unsigned char ); -extern void scsi_show_sense_hdr (struct scsi_sense_hdr *); +extern void scsi_show_extd_sense (char *,int ,unsigned char ,unsigned char ); +extern void scsi_show_sense_hdr (char *,int ,struct scsi_sense_hdr *);extern void scsi_print_sense_hdr (const char *,struct scsi_sense_hdr *);extern void scsi_cmd_print_sense_hdr (struct scsi_cmnd *,const char *,struct scsi_sense_hdr *);
Signature · 1 line
1.7.4.2
Quoted 26 lines · Hannes Reinecke
This patchset updates the SCSI midlayer to use
dev_printk()instead of the simpleprintk(). The main objective here is to avoid line-breaks in syslog output; with the current state it's nearly impossible to match the output to the occurring device; under high load even the CDB will be split off into individual bytes, spread randomly across the lines. Which makes debugging viascsi_logging_level_really_ hard. In addition we'll be getting the syslog messages nicely prefixed with the device, which will make userspace logging daemons happy.Before:
[ 297.300605] sd 2:0:3:2: Send: [ 297.300607] 0xffff8802348b0980 [ 297.300610] sd 2:0:3:2: CDB: [ 297.300615] Test Unit Ready: 00 00 00 00 00 00 [ 297.300747] sd 2:0:3:2: Done: [ 297.300750] 0xffff8802348b0980 SUCCESS [ 297.300753] sd 2:0:3:2: [ 297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 297.300758] sd 2:0:3:2: CDB: [ 297.300764] Test Unit Ready: 00 00 00 00 00 00 [ 297.300766] sd 2:0:3:2: [ 297.300769] Sense Key : Unit Attention [current] [ 297.300771] Info fld=0x0 [ 297.300772] sd 2:0:3:2: [ 297.300776] Add. Sense: Capacity data has changed
Quoted 8 lines
After:
[ 636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0 [ 636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS [ 636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current] [ 637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changed
I know there are a lot of changes here but shouldn't all this get fixed in stable 3.5+?
Thanks for sorting all this out Hannes.
Quoted 36 lines · Mike Snitzer
Quoted 26 lines · Hannes Reinecke
This patchset updates the SCSI midlayer to use
dev_printk()instead of the simpleprintk(). The main objective here is to avoid line-breaks in syslog output; with the current state it's nearly impossible to match the output to the occurring device; under high load even the CDB will be split off into individual bytes, spread randomly across the lines. Which makes debugging viascsi_logging_level_really_ hard. In addition we'll be getting the syslog messages nicely prefixed with the device, which will make userspace logging daemons happy.Before:
[ 297.300605] sd 2:0:3:2: Send: [ 297.300607] 0xffff8802348b0980 [ 297.300610] sd 2:0:3:2: CDB: [ 297.300615] Test Unit Ready: 00 00 00 00 00 00 [ 297.300747] sd 2:0:3:2: Done: [ 297.300750] 0xffff8802348b0980 SUCCESS [ 297.300753] sd 2:0:3:2: [ 297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 297.300758] sd 2:0:3:2: CDB: [ 297.300764] Test Unit Ready: 00 00 00 00 00 00 [ 297.300766] sd 2:0:3:2: [ 297.300769] Sense Key : Unit Attention [current] [ 297.300771] Info fld=0x0 [ 297.300772] sd 2:0:3:2: [ 297.300776] Add. Sense: Capacity data has changedQuoted 8 lines
After:
[ 636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0 [ 636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS [ 636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current] [ 637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changed
Quoted 3 lines
I know there are a lot of changes here but shouldn't all this get fixed in stable 3.5+?
If you ask me, yes, of course.
I can easily post a v2 of the patchset (meanwhile I've got another patch for st :-), Cc'ing stable with it.
Cheers,
Hannes
Signature · 8 lines
Dr. Hannes Reinecke zSeries & Storage [email protected] +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 [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
Hi Hannes, James,
I'm wondering what happened to this patch-set? I think it could make parsing of the output for userspace programs much easier. Are there some problems still to solve or is this just forgotten?
Thanks,
Tomas
Quoted 61 lines · Hannes Reinecke
This patchset updates the SCSI midlayer to use
dev_printk()instead of the simpleprintk(). The main objective here is to avoid line-breaks in syslog output; with the current state it's nearly impossible to match the output to the occurring device; under high load even the CDB will be split off into individual bytes, spread randomly across the lines. Which makes debugging viascsi_logging_level_really_ hard. In addition we'll be getting the syslog messages nicely prefixed with the device, which will make userspace logging daemons happy.Before:
[ 297.300605] sd 2:0:3:2: Send: [ 297.300607] 0xffff8802348b0980 [ 297.300610] sd 2:0:3:2: CDB: [ 297.300615] Test Unit Ready: 00 00 00 00 00 00 [ 297.300747] sd 2:0:3:2: Done: [ 297.300750] 0xffff8802348b0980 SUCCESS [ 297.300753] sd 2:0:3:2: [ 297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 297.300758] sd 2:0:3:2: CDB: [ 297.300764] Test Unit Ready: 00 00 00 00 00 00 [ 297.300766] sd 2:0:3:2: [ 297.300769] Sense Key : Unit Attention [current] [ 297.300771] Info fld=0x0 [ 297.300772] sd 2:0:3:2: [ 297.300776] Add. Sense: Capacity data has changedAfter:
[ 636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0 [ 636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS [ 636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK [ 636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00 [ 636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current] [ 637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changedHannes Reinecke (10):
sg: Usedev_printk
sr: Usedev_printk()
scsi: Avoid linebreaks in syslog output
scsi: Usesdev_printk()for logging
scsi: use buffer forprint_opcode_name()
scsi: use single printk call inscsi_print_command()
scsi: use buffer forscsi_show_result()
scsi: open-codescsi_decode_sense_buffer()
scsi: decode descriptor sense
scsi: use local buffer for decoding sense datadrivers/scsi/constants.c | 406 +++++++++++++++++++++++++-------------------- drivers/scsi/scsi.c | 54 ++++--- drivers/scsi/scsi_error.c | 190 ++++++++++++++------- drivers/scsi/scsi_lib.c | 13 +- drivers/scsi/scsi_scan.c | 68 ++++---- drivers/scsi/sd.c | 16 +- drivers/scsi/sg.c | 187 ++++++++++++--------- drivers/scsi/sr.c | 47 +++--- drivers/scsi/sr.h | 4 + include/scsi/scsi_dbg.h | 6 +- include/scsi/scsi_eh.h | 8 +- 11 files changed, 588 insertions(+), 411 deletions(-)
Quoted 6 lines · Tomas Henzl
Hi Hannes, James,
I'm wondering what happened to this patch-set? I think it could make parsing of the output for userspace programs much easier. Are there some problems still to solve or is this just forgotten?
Oh, no. Quite the contrary.
As James has now merged my previous patchsets I'm in the process of updating this one, too.
It'll be part of a larger patchset having a per-device scsi_logging_level; something I was wanting to have for a _LONG_ time now.
Currently I'm fiddling with sense code printing, so I won't be able to send anything this year. But early next year I should have something presentable.
Cheers,
Hannes
Signature · 8 lines
Dr. Hannes Reinecke zSeries & Storage [email protected] +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 [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
Quoted 11 lines · Hannes Reinecke
Quoted 6 lines · Tomas Henzl
Hi Hannes, James,
I'm wondering what happened to this patch-set? I think it could make parsing of the output for userspace programs much easier. Are there some problems still to solve or is this just forgotten?
Oh, no. Quite the contrary.
As James has now merged my previous patchsets I'm in the process of updating this one, too.
Quoted 7 lines
It'll be part of a larger patchset having a per-device
scsi_logging_level; something I was wanting to have for a _LONG_ time now.Currently I'm fiddling with sense code printing, so I won't be able to send anything this year. But early next year I should have something presentable.
Great news! thanks.
Quoted 4 lines
Cheers,
Hannes