| Message ID | 20220121164938.18190-1-jpittman@redhat.com |
|---|---|
| State | New |
| Headers | show |
| Series | scsi: print actual pointer addresses if using scsi debug logging | expand |
On 1/21/22 17:49, John Pittman wrote: > Since commit ad67b74d2469 ("printk: hash addresses printed with > %p"), any addresses printed with an unadorned %p will be hashed. > However, when scsi debug logging is enabled, in general, the > user needs the actual address for use with address tracking or > vmcore analysis. Print the actual address for pointers when > using the SCSI_LOG_* macros. While scsi_logging_level defaults to 0, i.e. all disabled, and it requires root privileges to increase it, I wonder how unconditionally unmodified addresses for scsi logging would relate to KASLR. Why not have the root user use no_hash_pointers with the existing plain pointers %p when setting scsi_logging_level? That way, it would be a clear and deliberate unhashing choice to be done by higher powers. Is it because changing no_hash_pointers does not seem dynamic as opposed to changing scsi_logging_level? I could not find such info in the patch description. Or would you delegate user access control to unmodified addresses in scsi logging kernel messages to https://www.kernel.org/doc/html/latest/admin-guide/sysctl/kernel.html#dmesg-restrict ? While still not being unambiguous, I often try to use the CDB for correlation of scsi logs with pending (request) objects in a crash dump. Would that be an alternative to pointers? AFAIK, with scsi_cmnd being re-used, the pointers are not unique for a particular request as time progresses. Enabling SCSI tracepoints on top can also be useful. References https://www.kernel.org/doc/html/latest/core-api/printk-formats.html#plain-pointers "If not possible, and the aim of printing the address is to provide more information for debugging, use %p and boot the kernel with the no_hash_pointers parameter during debugging, which will print all %p addresses unmodified." https://www.kernel.org/doc/html/latest/core-api/printk-formats.html#unmodified-addresses "Before using %px, consider if using %p is sufficient together with enabling the no_hash_pointers kernel parameter during debugging sessions" > > Signed-off-by: John Pittman <jpittman@redhat.com> > Collab-from: David Jeffery <djeffery@redhat.com> > --- > drivers/scsi/scsi.c | 2 +- > drivers/scsi/scsi_lib.c | 2 +- > drivers/scsi/sg.c | 8 ++++---- > drivers/scsi/sr.c | 2 +- > 4 files changed, 7 insertions(+), 7 deletions(-) > > diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c > index 211aace69c22..0f558135637c 100644 > --- a/drivers/scsi/scsi.c > +++ b/drivers/scsi/scsi.c > @@ -106,7 +106,7 @@ void scsi_log_send(struct scsi_cmnd *cmd) > SCSI_LOG_MLQUEUE_BITS); > if (level > 1) { > scmd_printk(KERN_INFO, cmd, > - "Send: scmd 0x%p\n", cmd); > + "Send: scmd 0x%px\n", cmd); > scsi_print_command(cmd); > } > } > diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c > index 35e381f6d371..a25ab894383b 100644 > --- a/drivers/scsi/scsi_lib.c > +++ b/drivers/scsi/scsi_lib.c > @@ -148,7 +148,7 @@ static void __scsi_queue_insert(struct scsi_cmnd *cmd, int reason, bool unbusy) > struct scsi_device *device = cmd->device; > > SCSI_LOG_MLQUEUE(1, scmd_printk(KERN_INFO, cmd, > - "Inserting command %p into mlqueue\n", cmd)); > + "Inserting command %px into mlqueue\n", cmd)); > > scsi_set_blocked(cmd, reason); > > diff --git a/drivers/scsi/sg.c b/drivers/scsi/sg.c > index ad12b3261845..2b11dc84d04b 100644 > --- a/drivers/scsi/sg.c > +++ b/drivers/scsi/sg.c > @@ -1274,7 +1274,7 @@ sg_mmap(struct file *filp, struct vm_area_struct *vma) > return -ENXIO; > req_sz = vma->vm_end - vma->vm_start; > SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sfp->parentdp, > - "sg_mmap starting, vm_start=%p, len=%d\n", > + "sg_mmap starting, vm_start=%px, len=%d\n", > (void *) vma->vm_start, (int) req_sz)); > if (vma->vm_pgoff) > return -EINVAL; /* want no offset */ > @@ -1944,7 +1944,7 @@ sg_remove_scat(Sg_fd * sfp, Sg_scatter_hold * schp) > for (k = 0; k < schp->k_use_sg && schp->pages[k]; k++) { > SCSI_LOG_TIMEOUT(5, > sg_printk(KERN_INFO, sfp->parentdp, > - "sg_remove_scat: k=%d, pg=0x%p\n", > + "sg_remove_scat: k=%d, pg=0x%px\n", > k, schp->pages[k])); > __free_pages(schp->pages[k], schp->page_order); > } > @@ -2156,7 +2156,7 @@ sg_add_sfp(Sg_device * sdp) > list_add_tail(&sfp->sfd_siblings, &sdp->sfds); > write_unlock_irqrestore(&sdp->sfd_lock, iflags); > SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp, > - "sg_add_sfp: sfp=0x%p\n", sfp)); > + "sg_add_sfp: sfp=0x%px\n", sfp)); > if (unlikely(sg_big_buff != def_reserved_size)) > sg_big_buff = def_reserved_size; > > @@ -2200,7 +2200,7 @@ sg_remove_sfp_usercontext(struct work_struct *work) > } > > SCSI_LOG_TIMEOUT(6, sg_printk(KERN_INFO, sdp, > - "sg_remove_sfp: sfp=0x%p\n", sfp)); > + "sg_remove_sfp: sfp=0x%px\n", sfp)); > kfree(sfp); > > scsi_device_put(sdp->device); > diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c > index f925b1f1f9ad..3b942c99a783 100644 > --- a/drivers/scsi/sr.c > +++ b/drivers/scsi/sr.c > @@ -411,7 +411,7 @@ static blk_status_t sr_init_command(struct scsi_cmnd *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)); > + "Retry with 0x%px\n", SCpnt)); > goto out; > } >
Thanks for looking Steffen. I failed to notice the no_hash_pointers option. I do think it would be a reasonable convenience for debug scsi logging to print the actual address without having to go through the trouble of rebooting enabling the no_hash_pointers parameter then rebooting again to disable afterward. Perhaps the system is a production box that can't be rebooted. Maybe an additional sysctl to enable no_hash_pointers would be reasonable? That way it could be changed online? Thanks again. On Fri, Jan 21, 2022 at 1:24 PM Steffen Maier <maier@linux.ibm.com> wrote: > > On 1/21/22 17:49, John Pittman wrote: > > Since commit ad67b74d2469 ("printk: hash addresses printed with > > %p"), any addresses printed with an unadorned %p will be hashed. > > However, when scsi debug logging is enabled, in general, the > > user needs the actual address for use with address tracking or > > vmcore analysis. Print the actual address for pointers when > > using the SCSI_LOG_* macros. > > While scsi_logging_level defaults to 0, i.e. all disabled, and it requires root > privileges to increase it, I wonder how unconditionally unmodified addresses > for scsi logging would relate to KASLR. > > Why not have the root user use no_hash_pointers with the existing plain > pointers %p when setting scsi_logging_level? > That way, it would be a clear and deliberate unhashing choice to be done by > higher powers. > Is it because changing no_hash_pointers does not seem dynamic as opposed to > changing scsi_logging_level? I could not find such info in the patch description. > Or would you delegate user access control to unmodified addresses in scsi > logging kernel messages to > https://www.kernel.org/doc/html/latest/admin-guide/sysctl/kernel.html#dmesg-restrict > ? > > While still not being unambiguous, I often try to use the CDB for correlation > of scsi logs with pending (request) objects in a crash dump. Would that be an > alternative to pointers? AFAIK, with scsi_cmnd being re-used, the pointers are > not unique for a particular request as time progresses. > Enabling SCSI tracepoints on top can also be useful. > > References > > https://www.kernel.org/doc/html/latest/core-api/printk-formats.html#plain-pointers > "If not possible, and the aim of printing the address is to provide more > information for debugging, use %p and boot the kernel with the no_hash_pointers > parameter during debugging, which will print all %p addresses unmodified." > > https://www.kernel.org/doc/html/latest/core-api/printk-formats.html#unmodified-addresses > "Before using %px, consider if using %p is sufficient together with enabling > the no_hash_pointers kernel parameter during debugging sessions" > > > > > Signed-off-by: John Pittman <jpittman@redhat.com> > > Collab-from: David Jeffery <djeffery@redhat.com> > > --- > > drivers/scsi/scsi.c | 2 +- > > drivers/scsi/scsi_lib.c | 2 +- > > drivers/scsi/sg.c | 8 ++++---- > > drivers/scsi/sr.c | 2 +- > > 4 files changed, 7 insertions(+), 7 deletions(-) > > > > diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c > > index 211aace69c22..0f558135637c 100644 > > --- a/drivers/scsi/scsi.c > > +++ b/drivers/scsi/scsi.c > > @@ -106,7 +106,7 @@ void scsi_log_send(struct scsi_cmnd *cmd) > > SCSI_LOG_MLQUEUE_BITS); > > if (level > 1) { > > scmd_printk(KERN_INFO, cmd, > > - "Send: scmd 0x%p\n", cmd); > > + "Send: scmd 0x%px\n", cmd); > > scsi_print_command(cmd); > > } > > } > > diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c > > index 35e381f6d371..a25ab894383b 100644 > > --- a/drivers/scsi/scsi_lib.c > > +++ b/drivers/scsi/scsi_lib.c > > @@ -148,7 +148,7 @@ static void __scsi_queue_insert(struct scsi_cmnd *cmd, int reason, bool unbusy) > > struct scsi_device *device = cmd->device; > > > > SCSI_LOG_MLQUEUE(1, scmd_printk(KERN_INFO, cmd, > > - "Inserting command %p into mlqueue\n", cmd)); > > + "Inserting command %px into mlqueue\n", cmd)); > > > > scsi_set_blocked(cmd, reason); > > > > diff --git a/drivers/scsi/sg.c b/drivers/scsi/sg.c > > index ad12b3261845..2b11dc84d04b 100644 > > --- a/drivers/scsi/sg.c > > +++ b/drivers/scsi/sg.c > > @@ -1274,7 +1274,7 @@ sg_mmap(struct file *filp, struct vm_area_struct *vma) > > return -ENXIO; > > req_sz = vma->vm_end - vma->vm_start; > > SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sfp->parentdp, > > - "sg_mmap starting, vm_start=%p, len=%d\n", > > + "sg_mmap starting, vm_start=%px, len=%d\n", > > (void *) vma->vm_start, (int) req_sz)); > > if (vma->vm_pgoff) > > return -EINVAL; /* want no offset */ > > @@ -1944,7 +1944,7 @@ sg_remove_scat(Sg_fd * sfp, Sg_scatter_hold * schp) > > for (k = 0; k < schp->k_use_sg && schp->pages[k]; k++) { > > SCSI_LOG_TIMEOUT(5, > > sg_printk(KERN_INFO, sfp->parentdp, > > - "sg_remove_scat: k=%d, pg=0x%p\n", > > + "sg_remove_scat: k=%d, pg=0x%px\n", > > k, schp->pages[k])); > > __free_pages(schp->pages[k], schp->page_order); > > } > > @@ -2156,7 +2156,7 @@ sg_add_sfp(Sg_device * sdp) > > list_add_tail(&sfp->sfd_siblings, &sdp->sfds); > > write_unlock_irqrestore(&sdp->sfd_lock, iflags); > > SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp, > > - "sg_add_sfp: sfp=0x%p\n", sfp)); > > + "sg_add_sfp: sfp=0x%px\n", sfp)); > > if (unlikely(sg_big_buff != def_reserved_size)) > > sg_big_buff = def_reserved_size; > > > > @@ -2200,7 +2200,7 @@ sg_remove_sfp_usercontext(struct work_struct *work) > > } > > > > SCSI_LOG_TIMEOUT(6, sg_printk(KERN_INFO, sdp, > > - "sg_remove_sfp: sfp=0x%p\n", sfp)); > > + "sg_remove_sfp: sfp=0x%px\n", sfp)); > > kfree(sfp); > > > > scsi_device_put(sdp->device); > > diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c > > index f925b1f1f9ad..3b942c99a783 100644 > > --- a/drivers/scsi/sr.c > > +++ b/drivers/scsi/sr.c > > @@ -411,7 +411,7 @@ static blk_status_t sr_init_command(struct scsi_cmnd *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)); > > + "Retry with 0x%px\n", SCpnt)); > > goto out; > > } > > > > > -- > Mit freundlichen Gruessen / Kind regards > Steffen Maier > > Linux on IBM Z and LinuxONE > > https://www.ibm.com/privacy/us/en/ > IBM Deutschland Research & Development GmbH > Vorsitzender des Aufsichtsrats: Gregor Pillen > Geschaeftsfuehrung: David Faller, Dirk Wittkopp > Sitz der Gesellschaft: Boeblingen > Registergericht: Amtsgericht Stuttgart, HRB 243294 >
On 1/21/22 11:17, John Pittman wrote: > Thanks for looking Steffen. I failed to notice the no_hash_pointers > option. I do think it would be a reasonable convenience for debug > scsi logging to print the actual address without having to go through > the trouble of rebooting enabling the no_hash_pointers parameter then > rebooting again to disable afterward. Perhaps the system is a > production box that can't be rebooted. Maybe an additional sysctl to > enable no_hash_pointers would be reasonable? That way it could be > changed online? Thanks again. Are SCSI command pointers really useful to anyone? How about modifying the debug statements such that the SCSI command tags are reported instead of the SCSI command pointers? There is a 1:1 correspondence between the values returned by blk_mq_unique_tag() and the SCSI command pointers. Bart.
diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c index 211aace69c22..0f558135637c 100644 --- a/drivers/scsi/scsi.c +++ b/drivers/scsi/scsi.c @@ -106,7 +106,7 @@ void scsi_log_send(struct scsi_cmnd *cmd) SCSI_LOG_MLQUEUE_BITS); if (level > 1) { scmd_printk(KERN_INFO, cmd, - "Send: scmd 0x%p\n", cmd); + "Send: scmd 0x%px\n", cmd); scsi_print_command(cmd); } } diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c index 35e381f6d371..a25ab894383b 100644 --- a/drivers/scsi/scsi_lib.c +++ b/drivers/scsi/scsi_lib.c @@ -148,7 +148,7 @@ static void __scsi_queue_insert(struct scsi_cmnd *cmd, int reason, bool unbusy) struct scsi_device *device = cmd->device; SCSI_LOG_MLQUEUE(1, scmd_printk(KERN_INFO, cmd, - "Inserting command %p into mlqueue\n", cmd)); + "Inserting command %px into mlqueue\n", cmd)); scsi_set_blocked(cmd, reason); diff --git a/drivers/scsi/sg.c b/drivers/scsi/sg.c index ad12b3261845..2b11dc84d04b 100644 --- a/drivers/scsi/sg.c +++ b/drivers/scsi/sg.c @@ -1274,7 +1274,7 @@ sg_mmap(struct file *filp, struct vm_area_struct *vma) return -ENXIO; req_sz = vma->vm_end - vma->vm_start; SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sfp->parentdp, - "sg_mmap starting, vm_start=%p, len=%d\n", + "sg_mmap starting, vm_start=%px, len=%d\n", (void *) vma->vm_start, (int) req_sz)); if (vma->vm_pgoff) return -EINVAL; /* want no offset */ @@ -1944,7 +1944,7 @@ sg_remove_scat(Sg_fd * sfp, Sg_scatter_hold * schp) for (k = 0; k < schp->k_use_sg && schp->pages[k]; k++) { SCSI_LOG_TIMEOUT(5, sg_printk(KERN_INFO, sfp->parentdp, - "sg_remove_scat: k=%d, pg=0x%p\n", + "sg_remove_scat: k=%d, pg=0x%px\n", k, schp->pages[k])); __free_pages(schp->pages[k], schp->page_order); } @@ -2156,7 +2156,7 @@ sg_add_sfp(Sg_device * sdp) list_add_tail(&sfp->sfd_siblings, &sdp->sfds); write_unlock_irqrestore(&sdp->sfd_lock, iflags); SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp, - "sg_add_sfp: sfp=0x%p\n", sfp)); + "sg_add_sfp: sfp=0x%px\n", sfp)); if (unlikely(sg_big_buff != def_reserved_size)) sg_big_buff = def_reserved_size; @@ -2200,7 +2200,7 @@ sg_remove_sfp_usercontext(struct work_struct *work) } SCSI_LOG_TIMEOUT(6, sg_printk(KERN_INFO, sdp, - "sg_remove_sfp: sfp=0x%p\n", sfp)); + "sg_remove_sfp: sfp=0x%px\n", sfp)); kfree(sfp); scsi_device_put(sdp->device); diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c index f925b1f1f9ad..3b942c99a783 100644 --- a/drivers/scsi/sr.c +++ b/drivers/scsi/sr.c @@ -411,7 +411,7 @@ static blk_status_t sr_init_command(struct scsi_cmnd *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)); + "Retry with 0x%px\n", SCpnt)); goto out; }
Since commit ad67b74d2469 ("printk: hash addresses printed with %p"), any addresses printed with an unadorned %p will be hashed. However, when scsi debug logging is enabled, in general, the user needs the actual address for use with address tracking or vmcore analysis. Print the actual address for pointers when using the SCSI_LOG_* macros. Signed-off-by: John Pittman <jpittman@redhat.com> Collab-from: David Jeffery <djeffery@redhat.com> --- drivers/scsi/scsi.c | 2 +- drivers/scsi/scsi_lib.c | 2 +- drivers/scsi/sg.c | 8 ++++---- drivers/scsi/sr.c | 2 +- 4 files changed, 7 insertions(+), 7 deletions(-)