From f8ec26d0f5bcdb864f771fb6d250d9ed3165eb61 Mon Sep 17 00:00:00 2001 From: Hannes Reinecke Date: Tue, 21 Dec 2021 08:20:29 +0100 Subject: ata: libata: add reset tracepoints To follow the flow of control we should be using tracepoints, as they will tie in with the actual I/O flow and deliver a better overview about what it happening. This patch adds tracepoints for hard reset, soft reset, and postreset and adds them in the libata-eh control flow. With that we can drop the reset DPRINTK calls in the various drivers. Signed-off-by: Hannes Reinecke Signed-off-by: Damien Le Moal --- include/trace/events/libata.h | 96 +++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 96 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/libata.h b/include/trace/events/libata.h index ab69434e2329..ec2a350d1aca 100644 --- a/include/trace/events/libata.h +++ b/include/trace/events/libata.h @@ -132,6 +132,22 @@ ata_protocol_name(ATAPI_PROT_PIO), \ ata_protocol_name(ATAPI_PROT_DMA)) +#define ata_class_name(class) { class, #class } +#define show_class_name(val) \ + __print_symbolic(val, \ + ata_class_name(ATA_DEV_UNKNOWN), \ + ata_class_name(ATA_DEV_ATA), \ + ata_class_name(ATA_DEV_ATA_UNSUP), \ + ata_class_name(ATA_DEV_ATAPI), \ + ata_class_name(ATA_DEV_ATAPI_UNSUP), \ + ata_class_name(ATA_DEV_PMP), \ + ata_class_name(ATA_DEV_PMP_UNSUP), \ + ata_class_name(ATA_DEV_SEMB), \ + ata_class_name(ATA_DEV_SEMB_UNSUP), \ + ata_class_name(ATA_DEV_ZAC), \ + ata_class_name(ATA_DEV_ZAC_UNSUP), \ + ata_class_name(ATA_DEV_NONE)) + const char *libata_trace_parse_status(struct trace_seq*, unsigned char); #define __parse_status(s) libata_trace_parse_status(p, s) @@ -329,6 +345,86 @@ TRACE_EVENT(ata_eh_link_autopsy_qc, __parse_eh_err_mask(__entry->eh_err_mask)) ); +DECLARE_EVENT_CLASS(ata_link_reset_begin_template, + + TP_PROTO(struct ata_link *link, unsigned int *class, unsigned long deadline), + + TP_ARGS(link, class, deadline), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __array( unsigned int, class, 2 ) + __field( unsigned long, deadline ) + ), + + TP_fast_assign( + __entry->ata_port = link->ap->print_id; + memcpy(__entry->class, class, 2); + __entry->deadline = deadline; + ), + + TP_printk("ata_port=%u deadline=%lu classes=[%s,%s]", + __entry->ata_port, __entry->deadline, + show_class_name(__entry->class[0]), + show_class_name(__entry->class[1])) +); + +DEFINE_EVENT(ata_link_reset_begin_template, ata_link_hardreset_begin, + TP_PROTO(struct ata_link *link, unsigned int *class, unsigned long deadline), + TP_ARGS(link, class, deadline)); + +DEFINE_EVENT(ata_link_reset_begin_template, ata_slave_hardreset_begin, + TP_PROTO(struct ata_link *link, unsigned int *class, unsigned long deadline), + TP_ARGS(link, class, deadline)); + +DEFINE_EVENT(ata_link_reset_begin_template, ata_link_softreset_begin, + TP_PROTO(struct ata_link *link, unsigned int *class, unsigned long deadline), + TP_ARGS(link, class, deadline)); + +DECLARE_EVENT_CLASS(ata_link_reset_end_template, + + TP_PROTO(struct ata_link *link, unsigned int *class, int rc), + + TP_ARGS(link, class, rc), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __array( unsigned int, class, 2 ) + __field( int, rc ) + ), + + TP_fast_assign( + __entry->ata_port = link->ap->print_id; + memcpy(__entry->class, class, 2); + __entry->rc = rc; + ), + + TP_printk("ata_port=%u rc=%d class=[%s,%s]", + __entry->ata_port, __entry->rc, + show_class_name(__entry->class[0]), + show_class_name(__entry->class[1])) +); + +DEFINE_EVENT(ata_link_reset_end_template, ata_link_hardreset_end, + TP_PROTO(struct ata_link *link, unsigned int *class, int rc), + TP_ARGS(link, class, rc)); + +DEFINE_EVENT(ata_link_reset_end_template, ata_slave_hardreset_end, + TP_PROTO(struct ata_link *link, unsigned int *class, int rc), + TP_ARGS(link, class, rc)); + +DEFINE_EVENT(ata_link_reset_end_template, ata_link_softreset_end, + TP_PROTO(struct ata_link *link, unsigned int *class, int rc), + TP_ARGS(link, class, rc)); + +DEFINE_EVENT(ata_link_reset_end_template, ata_link_postreset, + TP_PROTO(struct ata_link *link, unsigned int *class, int rc), + TP_ARGS(link, class, rc)); + +DEFINE_EVENT(ata_link_reset_end_template, ata_slave_postreset, + TP_PROTO(struct ata_link *link, unsigned int *class, int rc), + TP_ARGS(link, class, rc)); + #endif /* _TRACE_LIBATA_H */ /* This part must be outside protection */ -- cgit v1.2.3 From fc914faad67f237528739ec717222a560c97e723 Mon Sep 17 00:00:00 2001 From: Hannes Reinecke Date: Tue, 21 Dec 2021 08:20:30 +0100 Subject: ata: libata: add qc_prep tracepoint Convert the existing ata_qc_issue() tracepoint into a template, and add tracepoints for ata_qc_prep() and ata_qc_issue() based on that template. Signed-off-by: Hannes Reinecke Signed-off-by: Damien Le Moal --- drivers/ata/libata-core.c | 1 + include/trace/events/libata.h | 10 +++++++++- 2 files changed, 10 insertions(+), 1 deletion(-) (limited to 'include/trace') diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c index c1946336f81e..846596fdd831 100644 --- a/drivers/ata/libata-core.c +++ b/drivers/ata/libata-core.c @@ -4892,6 +4892,7 @@ void ata_qc_issue(struct ata_queued_cmd *qc) return; } + trace_ata_qc_prep(qc); qc->err_mask |= ap->ops->qc_prep(qc); if (unlikely(qc->err_mask)) goto err; diff --git a/include/trace/events/libata.h b/include/trace/events/libata.h index ec2a350d1aca..2394fc2b2831 100644 --- a/include/trace/events/libata.h +++ b/include/trace/events/libata.h @@ -164,7 +164,7 @@ const char *libata_trace_parse_subcmd(struct trace_seq *, unsigned char, unsigned char, unsigned char); #define __parse_subcmd(c,f,h) libata_trace_parse_subcmd(p, c, f, h) -TRACE_EVENT(ata_qc_issue, +DECLARE_EVENT_CLASS(ata_qc_issue_template, TP_PROTO(struct ata_queued_cmd *qc), @@ -223,6 +223,14 @@ TRACE_EVENT(ata_qc_issue, __entry->dev) ); +DEFINE_EVENT(ata_qc_issue_template, ata_qc_prep, + TP_PROTO(struct ata_queued_cmd *qc), + TP_ARGS(qc)); + +DEFINE_EVENT(ata_qc_issue_template, ata_qc_issue, + TP_PROTO(struct ata_queued_cmd *qc), + TP_ARGS(qc)); + DECLARE_EVENT_CLASS(ata_qc_complete_template, TP_PROTO(struct ata_queued_cmd *qc), -- cgit v1.2.3 From c206a389c97c9533971cd05eed69b49f535cc193 Mon Sep 17 00:00:00 2001 From: Hannes Reinecke Date: Tue, 21 Dec 2021 08:20:31 +0100 Subject: ata: libata: tracepoints for bus-master DMA Add tracepoints for bus-master DMA and taskfile related functions. That allows us to drop the relevant DPRINTK() calls. Signed-off-by: Hannes Reinecke Signed-off-by: Damien Le Moal --- drivers/ata/ata_piix.c | 8 ++- drivers/ata/libata-core.c | 6 ++ drivers/ata/libata-sff.c | 44 +++++++------- drivers/ata/libata-trace.c | 18 ++++++ drivers/ata/pata_arasan_cf.c | 3 + drivers/ata/pata_octeon_cf.c | 18 +++--- drivers/ata/pata_pdc202xx_old.c | 2 - drivers/ata/pata_sil680.c | 1 - drivers/ata/sata_dwc_460ex.c | 59 ++++--------------- drivers/ata/sata_nv.c | 12 ++-- drivers/ata/sata_rcar.c | 2 - include/trace/events/libata.h | 125 ++++++++++++++++++++++++++++++++++++++++ 12 files changed, 201 insertions(+), 97 deletions(-) (limited to 'include/trace') diff --git a/drivers/ata/ata_piix.c b/drivers/ata/ata_piix.c index eb6bf30bd2e3..27b0d903f91f 100644 --- a/drivers/ata/ata_piix.c +++ b/drivers/ata/ata_piix.c @@ -77,6 +77,7 @@ #include #include #include +#include #define DRV_NAME "ata_piix" #define DRV_VERSION "2.13" @@ -816,10 +817,15 @@ static int piix_sidpr_set_lpm(struct ata_link *link, enum ata_lpm_policy policy, static bool piix_irq_check(struct ata_port *ap) { + unsigned char host_stat; + if (unlikely(!ap->ioaddr.bmdma_addr)) return false; - return ap->ops->bmdma_status(ap) & ATA_DMA_INTR; + host_stat = ap->ops->bmdma_status(ap); + trace_ata_bmdma_status(ap, host_stat); + + return host_stat & ATA_DMA_INTR; } #ifdef CONFIG_PM_SLEEP diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c index 846596fdd831..3db4fd2029ce 100644 --- a/drivers/ata/libata-core.c +++ b/drivers/ata/libata-core.c @@ -6576,3 +6576,9 @@ void ata_print_version(const struct device *dev, const char *version) dev_printk(KERN_DEBUG, dev, "version %s\n", version); } EXPORT_SYMBOL(ata_print_version); + +EXPORT_TRACEPOINT_SYMBOL_GPL(ata_tf_load); +EXPORT_TRACEPOINT_SYMBOL_GPL(ata_exec_command); +EXPORT_TRACEPOINT_SYMBOL_GPL(ata_bmdma_setup); +EXPORT_TRACEPOINT_SYMBOL_GPL(ata_bmdma_start); +EXPORT_TRACEPOINT_SYMBOL_GPL(ata_bmdma_status); diff --git a/drivers/ata/libata-sff.c b/drivers/ata/libata-sff.c index 4cc7c0606e06..76bd87691978 100644 --- a/drivers/ata/libata-sff.c +++ b/drivers/ata/libata-sff.c @@ -18,7 +18,7 @@ #include #include #include - +#include #include "libata.h" static struct workqueue_struct *ata_sff_wq; @@ -409,12 +409,6 @@ void ata_sff_tf_load(struct ata_port *ap, const struct ata_taskfile *tf) iowrite8(tf->hob_lbal, ioaddr->lbal_addr); iowrite8(tf->hob_lbam, ioaddr->lbam_addr); iowrite8(tf->hob_lbah, ioaddr->lbah_addr); - VPRINTK("hob: feat 0x%X nsect 0x%X, lba 0x%X 0x%X 0x%X\n", - tf->hob_feature, - tf->hob_nsect, - tf->hob_lbal, - tf->hob_lbam, - tf->hob_lbah); } if (is_addr) { @@ -423,18 +417,10 @@ void ata_sff_tf_load(struct ata_port *ap, const struct ata_taskfile *tf) iowrite8(tf->lbal, ioaddr->lbal_addr); iowrite8(tf->lbam, ioaddr->lbam_addr); iowrite8(tf->lbah, ioaddr->lbah_addr); - VPRINTK("feat 0x%X nsect 0x%X lba 0x%X 0x%X 0x%X\n", - tf->feature, - tf->nsect, - tf->lbal, - tf->lbam, - tf->lbah); } - if (tf->flags & ATA_TFLAG_DEVICE) { + if (tf->flags & ATA_TFLAG_DEVICE) iowrite8(tf->device, ioaddr->device_addr); - VPRINTK("device 0x%X\n", tf->device); - } ata_wait_idle(ap); } @@ -494,8 +480,6 @@ EXPORT_SYMBOL_GPL(ata_sff_tf_read); */ void ata_sff_exec_command(struct ata_port *ap, const struct ata_taskfile *tf) { - DPRINTK("ata%u: cmd 0x%X\n", ap->print_id, tf->command); - iowrite8(tf->command, ap->ioaddr.command_addr); ata_sff_pause(ap); } @@ -505,6 +489,7 @@ EXPORT_SYMBOL_GPL(ata_sff_exec_command); * ata_tf_to_host - issue ATA taskfile to host controller * @ap: port to which command is being issued * @tf: ATA taskfile register set + * @tag: tag of the associated command * * Issues ATA taskfile register set to ATA host controller, * with proper synchronization with interrupt handler and @@ -514,9 +499,12 @@ EXPORT_SYMBOL_GPL(ata_sff_exec_command); * spin_lock_irqsave(host lock) */ static inline void ata_tf_to_host(struct ata_port *ap, - const struct ata_taskfile *tf) + const struct ata_taskfile *tf, + unsigned int tag) { + trace_ata_tf_load(ap, tf); ap->ops->sff_tf_load(ap, tf); + trace_ata_exec_command(ap, tf, tag); ap->ops->sff_exec_command(ap, tf); } @@ -768,6 +756,7 @@ static void atapi_send_cdb(struct ata_port *ap, struct ata_queued_cmd *qc) case ATAPI_PROT_DMA: ap->hsm_task_state = HSM_ST_LAST; /* initiate bmdma */ + trace_ata_bmdma_start(ap, &qc->tf, qc->tag); ap->ops->bmdma_start(qc); break; #endif /* CONFIG_ATA_BMDMA */ @@ -1376,7 +1365,7 @@ unsigned int ata_sff_qc_issue(struct ata_queued_cmd *qc) if (qc->tf.flags & ATA_TFLAG_POLLING) ata_qc_set_polling(qc); - ata_tf_to_host(ap, &qc->tf); + ata_tf_to_host(ap, &qc->tf, qc->tag); ap->hsm_task_state = HSM_ST_LAST; if (qc->tf.flags & ATA_TFLAG_POLLING) @@ -1388,7 +1377,7 @@ unsigned int ata_sff_qc_issue(struct ata_queued_cmd *qc) if (qc->tf.flags & ATA_TFLAG_POLLING) ata_qc_set_polling(qc); - ata_tf_to_host(ap, &qc->tf); + ata_tf_to_host(ap, &qc->tf, qc->tag); if (qc->tf.flags & ATA_TFLAG_WRITE) { /* PIO data out protocol */ @@ -1418,7 +1407,7 @@ unsigned int ata_sff_qc_issue(struct ata_queued_cmd *qc) if (qc->tf.flags & ATA_TFLAG_POLLING) ata_qc_set_polling(qc); - ata_tf_to_host(ap, &qc->tf); + ata_tf_to_host(ap, &qc->tf, qc->tag); ap->hsm_task_state = HSM_ST_FIRST; @@ -2745,8 +2734,11 @@ unsigned int ata_bmdma_qc_issue(struct ata_queued_cmd *qc) case ATA_PROT_DMA: WARN_ON_ONCE(qc->tf.flags & ATA_TFLAG_POLLING); + trace_ata_tf_load(ap, &qc->tf); ap->ops->sff_tf_load(ap, &qc->tf); /* load tf registers */ + trace_ata_bmdma_setup(ap, &qc->tf, qc->tag); ap->ops->bmdma_setup(qc); /* set up bmdma */ + trace_ata_bmdma_start(ap, &qc->tf, qc->tag); ap->ops->bmdma_start(qc); /* initiate bmdma */ ap->hsm_task_state = HSM_ST_LAST; break; @@ -2754,7 +2746,9 @@ unsigned int ata_bmdma_qc_issue(struct ata_queued_cmd *qc) case ATAPI_PROT_DMA: WARN_ON_ONCE(qc->tf.flags & ATA_TFLAG_POLLING); + trace_ata_tf_load(ap, &qc->tf); ap->ops->sff_tf_load(ap, &qc->tf); /* load tf registers */ + trace_ata_bmdma_setup(ap, &qc->tf, qc->tag); ap->ops->bmdma_setup(qc); /* set up bmdma */ ap->hsm_task_state = HSM_ST_FIRST; @@ -2795,13 +2789,14 @@ unsigned int ata_bmdma_port_intr(struct ata_port *ap, struct ata_queued_cmd *qc) if (ap->hsm_task_state == HSM_ST_LAST && ata_is_dma(qc->tf.protocol)) { /* check status of DMA engine */ host_stat = ap->ops->bmdma_status(ap); - VPRINTK("ata%u: host_stat 0x%X\n", ap->print_id, host_stat); + trace_ata_bmdma_status(ap, host_stat); /* if it's not our irq... */ if (!(host_stat & ATA_DMA_INTR)) return ata_sff_idle_irq(ap); /* before we do anything else, clear DMA-Start bit */ + trace_ata_bmdma_stop(ap, &qc->tf, qc->tag); ap->ops->bmdma_stop(qc); bmdma_stopped = true; @@ -2870,6 +2865,7 @@ void ata_bmdma_error_handler(struct ata_port *ap) u8 host_stat; host_stat = ap->ops->bmdma_status(ap); + trace_ata_bmdma_status(ap, host_stat); /* BMDMA controllers indicate host bus error by * setting DMA_ERR bit and timing out. As it wasn't @@ -2881,6 +2877,7 @@ void ata_bmdma_error_handler(struct ata_port *ap) thaw = true; } + trace_ata_bmdma_stop(ap, &qc->tf, qc->tag); ap->ops->bmdma_stop(qc); /* if we're gonna thaw, make sure IRQ is clear */ @@ -2914,6 +2911,7 @@ void ata_bmdma_post_internal_cmd(struct ata_queued_cmd *qc) if (ata_is_dma(qc->tf.protocol)) { spin_lock_irqsave(ap->lock, flags); + trace_ata_bmdma_stop(ap, &qc->tf, qc->tag); ap->ops->bmdma_stop(qc); spin_unlock_irqrestore(ap->lock, flags); } diff --git a/drivers/ata/libata-trace.c b/drivers/ata/libata-trace.c index 08e001303a82..8a929e4414dc 100644 --- a/drivers/ata/libata-trace.c +++ b/drivers/ata/libata-trace.c @@ -38,6 +38,24 @@ libata_trace_parse_status(struct trace_seq *p, unsigned char status) return ret; } +const char * +libata_trace_parse_host_stat(struct trace_seq *p, unsigned char host_stat) +{ + const char *ret = trace_seq_buffer_ptr(p); + + trace_seq_printf(p, "{ "); + if (host_stat & ATA_DMA_INTR) + trace_seq_printf(p, "INTR "); + if (host_stat & ATA_DMA_ERR) + trace_seq_printf(p, "ERR "); + if (host_stat & ATA_DMA_ACTIVE) + trace_seq_printf(p, "ACTIVE "); + trace_seq_putc(p, '}'); + trace_seq_putc(p, 0); + + return ret; +} + const char * libata_trace_parse_eh_action(struct trace_seq *p, unsigned int eh_action) { diff --git a/drivers/ata/pata_arasan_cf.c b/drivers/ata/pata_arasan_cf.c index 63f39440a9b4..24c3d5e1fca3 100644 --- a/drivers/ata/pata_arasan_cf.c +++ b/drivers/ata/pata_arasan_cf.c @@ -39,6 +39,7 @@ #include #include #include +#include #define DRIVER_NAME "arasan_cf" #define TIMEOUT msecs_to_jiffies(3000) @@ -703,9 +704,11 @@ static unsigned int arasan_cf_qc_issue(struct ata_queued_cmd *qc) case ATA_PROT_DMA: WARN_ON_ONCE(qc->tf.flags & ATA_TFLAG_POLLING); + trace_ata_tf_load(ap, &qc->tf); ap->ops->sff_tf_load(ap, &qc->tf); acdev->dma_status = 0; acdev->qc = qc; + trace_ata_bmdma_start(ap, &qc->tf, qc->tag); arasan_cf_dma_start(acdev); ap->hsm_task_state = HSM_ST_LAST; break; diff --git a/drivers/ata/pata_octeon_cf.c b/drivers/ata/pata_octeon_cf.c index cdc95eb2b2cb..1fe756af3268 100644 --- a/drivers/ata/pata_octeon_cf.c +++ b/drivers/ata/pata_octeon_cf.c @@ -19,7 +19,7 @@ #include #include #include - +#include #include #include @@ -514,20 +514,14 @@ static void octeon_cf_exec_command16(struct ata_port *ap, { /* The base of the registers is at ioaddr.data_addr. */ void __iomem *base = ap->ioaddr.data_addr; - u16 blob; + u16 blob = 0; - if (tf->flags & ATA_TFLAG_DEVICE) { - VPRINTK("device 0x%X\n", tf->device); + if (tf->flags & ATA_TFLAG_DEVICE) blob = tf->device; - } else { - blob = 0; - } - DPRINTK("ata%u: cmd 0x%X\n", ap->print_id, tf->command); blob |= (tf->command << 8); __raw_writew(blob, base + 6); - ata_wait_idle(ap); } @@ -541,12 +535,10 @@ static void octeon_cf_dma_setup(struct ata_queued_cmd *qc) struct octeon_cf_port *cf_port; cf_port = ap->private_data; - DPRINTK("ENTER\n"); /* issue r/w command */ qc->cursg = qc->sg; cf_port->dma_finished = 0; ap->ops->sff_exec_command(ap, &qc->tf); - DPRINTK("EXIT\n"); } /** @@ -699,6 +691,7 @@ static irqreturn_t octeon_cf_interrupt(int irq, void *dev_instance) if (!sg_is_last(qc->cursg)) { qc->cursg = sg_next(qc->cursg); handled = 1; + trace_ata_bmdma_start(ap, &qc->tf, qc->tag); octeon_cf_dma_start(qc); continue; } else { @@ -798,8 +791,11 @@ static unsigned int octeon_cf_qc_issue(struct ata_queued_cmd *qc) case ATA_PROT_DMA: WARN_ON(qc->tf.flags & ATA_TFLAG_POLLING); + trace_ata_tf_load(ap, &qc->tf); ap->ops->sff_tf_load(ap, &qc->tf); /* load tf registers */ + trace_ata_bmdma_setup(ap, &qc->tf, qc->tag); octeon_cf_dma_setup(qc); /* set up dma */ + trace_ata_bmdma_start(ap, &qc->tf, qc->tag); octeon_cf_dma_start(qc); /* initiate dma */ ap->hsm_task_state = HSM_ST_LAST; break; diff --git a/drivers/ata/pata_pdc202xx_old.c b/drivers/ata/pata_pdc202xx_old.c index 0c5cbcd28d0d..b99849095853 100644 --- a/drivers/ata/pata_pdc202xx_old.c +++ b/drivers/ata/pata_pdc202xx_old.c @@ -38,8 +38,6 @@ static int pdc2026x_cable_detect(struct ata_port *ap) static void pdc202xx_exec_command(struct ata_port *ap, const struct ata_taskfile *tf) { - DPRINTK("ata%u: cmd 0x%X\n", ap->print_id, tf->command); - iowrite8(tf->command, ap->ioaddr.command_addr); ndelay(400); } diff --git a/drivers/ata/pata_sil680.c b/drivers/ata/pata_sil680.c index 43215a664b96..81238e097fe2 100644 --- a/drivers/ata/pata_sil680.c +++ b/drivers/ata/pata_sil680.c @@ -212,7 +212,6 @@ static void sil680_set_dmamode(struct ata_port *ap, struct ata_device *adev) static void sil680_sff_exec_command(struct ata_port *ap, const struct ata_taskfile *tf) { - DPRINTK("ata%u: cmd 0x%X\n", ap->print_id, tf->command); iowrite8(tf->command, ap->ioaddr.command_addr); ioread8(ap->ioaddr.bmdma_addr + ATA_DMA_CMD); } diff --git a/drivers/ata/sata_dwc_460ex.c b/drivers/ata/sata_dwc_460ex.c index bd4859563796..c33dc98e0d9d 100644 --- a/drivers/ata/sata_dwc_460ex.c +++ b/drivers/ata/sata_dwc_460ex.c @@ -34,6 +34,7 @@ #include #include #include +#include #include "libata.h" @@ -295,6 +296,7 @@ static const char *get_prot_descript(u8 protocol) } } +#ifdef DEBUG_NCQ static const char *get_dma_dir_descript(int dma_dir) { switch ((enum dma_data_direction)dma_dir) { @@ -308,21 +310,7 @@ static const char *get_dma_dir_descript(int dma_dir) return "none"; } } - -static void sata_dwc_tf_dump(struct ata_port *ap, struct ata_taskfile *tf) -{ - dev_vdbg(ap->dev, - "taskfile cmd: 0x%02x protocol: %s flags: 0x%lx device: %x\n", - tf->command, get_prot_descript(tf->protocol), tf->flags, - tf->device); - dev_vdbg(ap->dev, - "feature: 0x%02x nsect: 0x%x lbal: 0x%x lbam: 0x%x lbah: 0x%x\n", - tf->feature, tf->nsect, tf->lbal, tf->lbam, tf->lbah); - dev_vdbg(ap->dev, - "hob_feature: 0x%02x hob_nsect: 0x%x hob_lbal: 0x%x hob_lbam: 0x%x hob_lbah: 0x%x\n", - tf->hob_feature, tf->hob_nsect, tf->hob_lbal, tf->hob_lbam, - tf->hob_lbah); -} +#endif static void dma_dwc_xfer_done(void *hsdev_instance) { @@ -551,6 +539,7 @@ static irqreturn_t sata_dwc_isr(int irq, void *dev_instance) * active tag. It is the tag that matches the command about to * be completed. */ + trace_ata_bmdma_start(ap, &qc->tf, tag); qc->ap->link.active_tag = tag; sata_dwc_bmdma_start_by_tag(qc, tag); @@ -978,9 +967,6 @@ static void sata_dwc_exec_command_by_tag(struct ata_port *ap, { struct sata_dwc_device_port *hsdevp = HSDEVP_FROM_AP(ap); - dev_dbg(ap->dev, "%s cmd(0x%02x): %s tag=%d\n", __func__, tf->command, - ata_get_cmd_descript(tf->command), tag); - hsdevp->cmd_issued[tag] = cmd_issued; /* @@ -1003,12 +989,9 @@ static void sata_dwc_bmdma_setup(struct ata_queued_cmd *qc) { u8 tag = qc->hw_tag; - if (ata_is_ncq(qc->tf.protocol)) { - dev_dbg(qc->ap->dev, "%s: ap->link.sactive=0x%08x tag=%d\n", - __func__, qc->ap->link.sactive, tag); - } else { + if (!ata_is_ncq(qc->tf.protocol)) tag = 0; - } + sata_dwc_bmdma_setup_by_tag(qc, tag); } @@ -1035,12 +1018,6 @@ static void sata_dwc_bmdma_start_by_tag(struct ata_queued_cmd *qc, u8 tag) start_dma = 0; } - dev_dbg(ap->dev, - "%s qc=%p tag: %x cmd: 0x%02x dma_dir: %s start_dma? %x\n", - __func__, qc, tag, qc->tf.command, - get_dma_dir_descript(qc->dma_dir), start_dma); - sata_dwc_tf_dump(ap, &qc->tf); - if (start_dma) { sata_dwc_scr_read(&ap->link, SCR_ERROR, ®); if (reg & SATA_DWC_SERROR_ERR_BITS) { @@ -1065,13 +1042,9 @@ static void sata_dwc_bmdma_start(struct ata_queued_cmd *qc) { u8 tag = qc->hw_tag; - if (ata_is_ncq(qc->tf.protocol)) { - dev_dbg(qc->ap->dev, "%s: ap->link.sactive=0x%08x tag=%d\n", - __func__, qc->ap->link.sactive, tag); - } else { + if (!ata_is_ncq(qc->tf.protocol)) tag = 0; - } - dev_dbg(qc->ap->dev, "%s\n", __func__); + sata_dwc_bmdma_start_by_tag(qc, tag); } @@ -1082,16 +1055,6 @@ static unsigned int sata_dwc_qc_issue(struct ata_queued_cmd *qc) struct ata_port *ap = qc->ap; struct sata_dwc_device_port *hsdevp = HSDEVP_FROM_AP(ap); -#ifdef DEBUG_NCQ - if (qc->hw_tag > 0 || ap->link.sactive > 1) - dev_info(ap->dev, - "%s ap id=%d cmd(0x%02x)=%s qc tag=%d prot=%s ap active_tag=0x%08x ap sactive=0x%08x\n", - __func__, ap->print_id, qc->tf.command, - ata_get_cmd_descript(qc->tf.command), - qc->hw_tag, get_prot_descript(qc->tf.protocol), - ap->link.active_tag, ap->link.sactive); -#endif - if (!ata_is_ncq(qc->tf.protocol)) tag = 0; @@ -1108,11 +1071,9 @@ static unsigned int sata_dwc_qc_issue(struct ata_queued_cmd *qc) sactive |= (0x00000001 << tag); sata_dwc_scr_write(&ap->link, SCR_ACTIVE, sactive); - dev_dbg(qc->ap->dev, - "%s: tag=%d ap->link.sactive = 0x%08x sactive=0x%08x\n", - __func__, tag, qc->ap->link.sactive, sactive); - + trace_ata_tf_load(ap, &qc->tf); ap->ops->sff_tf_load(ap, &qc->tf); + trace_ata_exec_command(ap, &qc->tf, tag); sata_dwc_exec_command_by_tag(ap, &qc->tf, tag, SATA_DWC_CMD_ISSUED_PEND); } else { diff --git a/drivers/ata/sata_nv.c b/drivers/ata/sata_nv.c index 3c70405a0b80..06d381b9764e 100644 --- a/drivers/ata/sata_nv.c +++ b/drivers/ata/sata_nv.c @@ -31,6 +31,7 @@ #include #include #include +#include #define DRV_NAME "sata_nv" #define DRV_VERSION "3.5" @@ -1434,8 +1435,6 @@ static unsigned int nv_adma_qc_issue(struct ata_queued_cmd *qc) writew(qc->hw_tag, mmio + NV_ADMA_APPEND); - DPRINTK("Issued tag %u\n", qc->hw_tag); - return 0; } @@ -2013,19 +2012,17 @@ static unsigned int nv_swncq_issue_atacmd(struct ata_port *ap, if (qc == NULL) return 0; - DPRINTK("Enter\n"); - writel((1 << qc->hw_tag), pp->sactive_block); pp->last_issue_tag = qc->hw_tag; pp->dhfis_bits &= ~(1 << qc->hw_tag); pp->dmafis_bits &= ~(1 << qc->hw_tag); pp->qc_active |= (0x1 << qc->hw_tag); + trace_ata_tf_load(ap, &qc->tf); ap->ops->sff_tf_load(ap, &qc->tf); /* load tf registers */ + trace_ata_exec_command(ap, &qc->tf, qc->hw_tag); ap->ops->sff_exec_command(ap, &qc->tf); - DPRINTK("Issued tag %u\n", qc->hw_tag); - return 0; } @@ -2037,8 +2034,6 @@ static unsigned int nv_swncq_qc_issue(struct ata_queued_cmd *qc) if (qc->tf.protocol != ATA_PROT_NCQ) return ata_bmdma_qc_issue(qc); - DPRINTK("Enter\n"); - if (!pp->qc_active) nv_swncq_issue_atacmd(ap, qc); else @@ -2083,6 +2078,7 @@ static int nv_swncq_sdbfis(struct ata_port *ap) u8 lack_dhfis = 0; host_stat = ap->ops->bmdma_status(ap); + trace_ata_bmdma_status(ap, host_stat); if (unlikely(host_stat & ATA_DMA_ERR)) { /* error when transferring data to/from memory */ ata_ehi_clear_desc(ehi); diff --git a/drivers/ata/sata_rcar.c b/drivers/ata/sata_rcar.c index 9005833ab02f..b4994d182eda 100644 --- a/drivers/ata/sata_rcar.c +++ b/drivers/ata/sata_rcar.c @@ -436,8 +436,6 @@ static void sata_rcar_tf_read(struct ata_port *ap, struct ata_taskfile *tf) static void sata_rcar_exec_command(struct ata_port *ap, const struct ata_taskfile *tf) { - DPRINTK("ata%u: cmd 0x%X\n", ap->print_id, tf->command); - iowrite32(tf->command, ap->ioaddr.command_addr); ata_sff_pause(ap); } diff --git a/include/trace/events/libata.h b/include/trace/events/libata.h index 2394fc2b2831..acb9a4fc18ed 100644 --- a/include/trace/events/libata.h +++ b/include/trace/events/libata.h @@ -151,6 +151,9 @@ const char *libata_trace_parse_status(struct trace_seq*, unsigned char); #define __parse_status(s) libata_trace_parse_status(p, s) +const char *libata_trace_parse_host_stat(struct trace_seq *, unsigned char); +#define __parse_host_stat(s) libata_trace_parse_host_stat(p, s) + const char *libata_trace_parse_eh_action(struct trace_seq *, unsigned int); #define __parse_eh_action(a) libata_trace_parse_eh_action(p, a) @@ -299,6 +302,128 @@ DEFINE_EVENT(ata_qc_complete_template, ata_qc_complete_done, TP_PROTO(struct ata_queued_cmd *qc), TP_ARGS(qc)); +TRACE_EVENT(ata_tf_load, + + TP_PROTO(struct ata_port *ap, const struct ata_taskfile *tf), + + TP_ARGS(ap, tf), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __field( unsigned char, cmd ) + __field( unsigned char, dev ) + __field( unsigned char, lbal ) + __field( unsigned char, lbam ) + __field( unsigned char, lbah ) + __field( unsigned char, nsect ) + __field( unsigned char, feature ) + __field( unsigned char, hob_lbal ) + __field( unsigned char, hob_lbam ) + __field( unsigned char, hob_lbah ) + __field( unsigned char, hob_nsect ) + __field( unsigned char, hob_feature ) + __field( unsigned char, proto ) + ), + + TP_fast_assign( + __entry->ata_port = ap->print_id; + __entry->proto = tf->protocol; + __entry->cmd = tf->command; + __entry->dev = tf->device; + __entry->lbal = tf->lbal; + __entry->lbam = tf->lbam; + __entry->lbah = tf->lbah; + __entry->hob_lbal = tf->hob_lbal; + __entry->hob_lbam = tf->hob_lbam; + __entry->hob_lbah = tf->hob_lbah; + __entry->feature = tf->feature; + __entry->hob_feature = tf->hob_feature; + __entry->nsect = tf->nsect; + __entry->hob_nsect = tf->hob_nsect; + ), + + TP_printk("ata_port=%u proto=%s cmd=%s%s " \ + " tf=(%02x/%02x:%02x:%02x:%02x:%02x/%02x:%02x:%02x:%02x:%02x/%02x)", + __entry->ata_port, + show_protocol_name(__entry->proto), + show_opcode_name(__entry->cmd), + __parse_subcmd(__entry->cmd, __entry->feature, __entry->hob_nsect), + __entry->cmd, __entry->feature, __entry->nsect, + __entry->lbal, __entry->lbam, __entry->lbah, + __entry->hob_feature, __entry->hob_nsect, + __entry->hob_lbal, __entry->hob_lbam, __entry->hob_lbah, + __entry->dev) +); + +DECLARE_EVENT_CLASS(ata_exec_command_template, + + TP_PROTO(struct ata_port *ap, const struct ata_taskfile *tf, unsigned int tag), + + TP_ARGS(ap, tf, tag), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __field( unsigned int, tag ) + __field( unsigned char, cmd ) + __field( unsigned char, feature ) + __field( unsigned char, hob_nsect ) + __field( unsigned char, proto ) + ), + + TP_fast_assign( + __entry->ata_port = ap->print_id; + __entry->tag = tag; + __entry->proto = tf->protocol; + __entry->cmd = tf->command; + __entry->feature = tf->feature; + __entry->hob_nsect = tf->hob_nsect; + ), + + TP_printk("ata_port=%u tag=%d proto=%s cmd=%s%s", + __entry->ata_port, __entry->tag, + show_protocol_name(__entry->proto), + show_opcode_name(__entry->cmd), + __parse_subcmd(__entry->cmd, __entry->feature, __entry->hob_nsect)) +); + +DEFINE_EVENT(ata_exec_command_template, ata_exec_command, + TP_PROTO(struct ata_port *ap, const struct ata_taskfile *tf, unsigned int tag), + TP_ARGS(ap, tf, tag)); + +DEFINE_EVENT(ata_exec_command_template, ata_bmdma_setup, + TP_PROTO(struct ata_port *ap, const struct ata_taskfile *tf, unsigned int tag), + TP_ARGS(ap, tf, tag)); + +DEFINE_EVENT(ata_exec_command_template, ata_bmdma_start, + TP_PROTO(struct ata_port *ap, const struct ata_taskfile *tf, unsigned int tag), + TP_ARGS(ap, tf, tag)); + +DEFINE_EVENT(ata_exec_command_template, ata_bmdma_stop, + TP_PROTO(struct ata_port *ap, const struct ata_taskfile *tf, unsigned int tag), + TP_ARGS(ap, tf, tag)); + +TRACE_EVENT(ata_bmdma_status, + + TP_PROTO(struct ata_port *ap, unsigned int host_stat), + + TP_ARGS(ap, host_stat), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __field( unsigned int, tag ) + __field( unsigned char, host_stat ) + ), + + TP_fast_assign( + __entry->ata_port = ap->print_id; + __entry->host_stat = host_stat; + ), + + TP_printk("ata_port=%u host_stat=%s", + __entry->ata_port, + __parse_host_stat(__entry->host_stat)) +); + TRACE_EVENT(ata_eh_link_autopsy, TP_PROTO(struct ata_device *dev, unsigned int eh_action, unsigned int eh_err_mask), -- cgit v1.2.3 From 7fad6ad6a357c73f0bdf55476238ae2884de78a3 Mon Sep 17 00:00:00 2001 From: Hannes Reinecke Date: Tue, 21 Dec 2021 08:20:32 +0100 Subject: ata: libata-sff: tracepoints for HSM state machine Add tracepoints for the HSM state machine and drop DPRINTK calls Signed-off-by: Hannes Reinecke Signed-off-by: Damien Le Moal --- drivers/ata/libata-sff.c | 20 +++---- drivers/ata/libata-trace.c | 29 ++++++++++ include/trace/events/libata.h | 125 ++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 161 insertions(+), 13 deletions(-) (limited to 'include/trace') diff --git a/drivers/ata/libata-sff.c b/drivers/ata/libata-sff.c index 76bd87691978..b544bdc6d0a3 100644 --- a/drivers/ata/libata-sff.c +++ b/drivers/ata/libata-sff.c @@ -668,7 +668,7 @@ static void ata_pio_sector(struct ata_queued_cmd *qc) page = nth_page(page, (offset >> PAGE_SHIFT)); offset %= PAGE_SIZE; - DPRINTK("data %s\n", qc->tf.flags & ATA_TFLAG_WRITE ? "write" : "read"); + trace_ata_sff_pio_transfer_data(qc, offset, qc->sect_size); /* * Split the transfer when it splits a page boundary. Note that the @@ -738,7 +738,7 @@ static void ata_pio_sectors(struct ata_queued_cmd *qc) static void atapi_send_cdb(struct ata_port *ap, struct ata_queued_cmd *qc) { /* send SCSI cdb */ - DPRINTK("send cdb\n"); + trace_atapi_send_cdb(qc, 0, qc->dev->cdb_len); WARN_ON_ONCE(qc->dev->cdb_len < 12); ap->ops->sff_data_xfer(qc, qc->cdb, qc->dev->cdb_len, 1); @@ -809,7 +809,7 @@ next_sg: /* don't cross page boundaries */ count = min(count, (unsigned int)PAGE_SIZE - offset); - DPRINTK("data %s\n", qc->tf.flags & ATA_TFLAG_WRITE ? "write" : "read"); + trace_atapi_pio_transfer_data(qc, offset, count); /* do the actual data transfer */ buf = kmap_atomic(page); @@ -991,8 +991,7 @@ int ata_sff_hsm_move(struct ata_port *ap, struct ata_queued_cmd *qc, WARN_ON_ONCE(in_wq != ata_hsm_ok_in_wq(ap, qc)); fsm_start: - DPRINTK("ata%u: protocol %d task_state %d (dev_stat 0x%X)\n", - ap->print_id, qc->tf.protocol, ap->hsm_task_state, status); + trace_ata_sff_hsm_state(qc, status); switch (ap->hsm_task_state) { case HSM_ST_FIRST: @@ -1193,8 +1192,7 @@ fsm_start: } /* no more data to transfer */ - DPRINTK("ata%u: dev %u command complete, drv_stat 0x%x\n", - ap->print_id, qc->dev->devno, status); + trace_ata_sff_hsm_command_complete(qc, status); WARN_ON_ONCE(qc->err_mask & (AC_ERR_DEV | AC_ERR_HSM)); @@ -1251,7 +1249,7 @@ EXPORT_SYMBOL_GPL(ata_sff_queue_pio_task); void ata_sff_flush_pio_task(struct ata_port *ap) { - DPRINTK("ENTER\n"); + trace_ata_sff_flush_pio_task(ap); cancel_delayed_work_sync(&ap->sff_pio_task); @@ -1268,9 +1266,6 @@ void ata_sff_flush_pio_task(struct ata_port *ap) spin_unlock_irq(ap->lock); ap->sff_pio_task_link = NULL; - - if (ata_msg_ctl(ap)) - ata_port_dbg(ap, "%s: EXIT\n", __func__); } static void ata_sff_pio_task(struct work_struct *work) @@ -1467,8 +1462,7 @@ static unsigned int __ata_sff_port_intr(struct ata_port *ap, { u8 status; - VPRINTK("ata%u: protocol %d task_state %d\n", - ap->print_id, qc->tf.protocol, ap->hsm_task_state); + trace_ata_sff_port_intr(qc, hsmv_on_idle); /* Check whether we are expecting interrupt in this state */ switch (ap->hsm_task_state) { diff --git a/drivers/ata/libata-trace.c b/drivers/ata/libata-trace.c index 8a929e4414dc..e0e4d0d5a100 100644 --- a/drivers/ata/libata-trace.c +++ b/drivers/ata/libata-trace.c @@ -155,6 +155,35 @@ libata_trace_parse_qc_flags(struct trace_seq *p, unsigned int qc_flags) return ret; } +const char * +libata_trace_parse_tf_flags(struct trace_seq *p, unsigned int tf_flags) +{ + const char *ret = trace_seq_buffer_ptr(p); + + trace_seq_printf(p, "%x", tf_flags); + if (tf_flags) { + trace_seq_printf(p, "{ "); + if (tf_flags & ATA_TFLAG_LBA48) + trace_seq_printf(p, "LBA48 "); + if (tf_flags & ATA_TFLAG_ISADDR) + trace_seq_printf(p, "ISADDR "); + if (tf_flags & ATA_TFLAG_DEVICE) + trace_seq_printf(p, "DEV "); + if (tf_flags & ATA_TFLAG_WRITE) + trace_seq_printf(p, "WRITE "); + if (tf_flags & ATA_TFLAG_LBA) + trace_seq_printf(p, "LBA "); + if (tf_flags & ATA_TFLAG_FUA) + trace_seq_printf(p, "FUA "); + if (tf_flags & ATA_TFLAG_POLLING) + trace_seq_printf(p, "POLL "); + trace_seq_putc(p, '}'); + } + trace_seq_putc(p, 0); + + return ret; +} + const char * libata_trace_parse_subcmd(struct trace_seq *p, unsigned char cmd, unsigned char feature, unsigned char hob_nsect) diff --git a/include/trace/events/libata.h b/include/trace/events/libata.h index acb9a4fc18ed..fcb8fde39614 100644 --- a/include/trace/events/libata.h +++ b/include/trace/events/libata.h @@ -148,6 +148,15 @@ ata_class_name(ATA_DEV_ZAC_UNSUP), \ ata_class_name(ATA_DEV_NONE)) +#define ata_sff_hsm_state_name(state) { state, #state } +#define show_sff_hsm_state_name(val) \ + __print_symbolic(val, \ + ata_sff_hsm_state_name(HSM_ST_IDLE), \ + ata_sff_hsm_state_name(HSM_ST_FIRST), \ + ata_sff_hsm_state_name(HSM_ST), \ + ata_sff_hsm_state_name(HSM_ST_LAST), \ + ata_sff_hsm_state_name(HSM_ST_ERR)) + const char *libata_trace_parse_status(struct trace_seq*, unsigned char); #define __parse_status(s) libata_trace_parse_status(p, s) @@ -163,6 +172,9 @@ const char *libata_trace_parse_eh_err_mask(struct trace_seq *, unsigned int); const char *libata_trace_parse_qc_flags(struct trace_seq *, unsigned int); #define __parse_qc_flags(f) libata_trace_parse_qc_flags(p, f) +const char *libata_trace_parse_tf_flags(struct trace_seq *, unsigned int); +#define __parse_tf_flags(f) libata_trace_parse_tf_flags(p, f) + const char *libata_trace_parse_subcmd(struct trace_seq *, unsigned char, unsigned char, unsigned char); #define __parse_subcmd(c,f,h) libata_trace_parse_subcmd(p, c, f, h) @@ -558,6 +570,119 @@ DEFINE_EVENT(ata_link_reset_end_template, ata_slave_postreset, TP_PROTO(struct ata_link *link, unsigned int *class, int rc), TP_ARGS(link, class, rc)); +DECLARE_EVENT_CLASS(ata_sff_hsm_template, + + TP_PROTO(struct ata_queued_cmd *qc, unsigned char status), + + TP_ARGS(qc, status), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __field( unsigned int, ata_dev ) + __field( unsigned int, tag ) + __field( unsigned int, qc_flags ) + __field( unsigned int, protocol ) + __field( unsigned int, hsm_state ) + __field( unsigned char, dev_state ) + ), + + TP_fast_assign( + __entry->ata_port = qc->ap->print_id; + __entry->ata_dev = qc->dev->link->pmp + qc->dev->devno; + __entry->tag = qc->tag; + __entry->qc_flags = qc->flags; + __entry->protocol = qc->tf.protocol; + __entry->hsm_state = qc->ap->hsm_task_state; + __entry->dev_state = status; + ), + + TP_printk("ata_port=%u ata_dev=%u tag=%d proto=%s flags=%s task_state=%s dev_stat=0x%X", + __entry->ata_port, __entry->ata_dev, __entry->tag, + show_protocol_name(__entry->protocol), + __parse_qc_flags(__entry->qc_flags), + show_sff_hsm_state_name(__entry->hsm_state), + __entry->dev_state) +); + +DEFINE_EVENT(ata_sff_hsm_template, ata_sff_hsm_state, + TP_PROTO(struct ata_queued_cmd *qc, unsigned char state), + TP_ARGS(qc, state)); + +DEFINE_EVENT(ata_sff_hsm_template, ata_sff_hsm_command_complete, + TP_PROTO(struct ata_queued_cmd *qc, unsigned char state), + TP_ARGS(qc, state)); + +DEFINE_EVENT(ata_sff_hsm_template, ata_sff_port_intr, + TP_PROTO(struct ata_queued_cmd *qc, unsigned char state), + TP_ARGS(qc, state)); + +DECLARE_EVENT_CLASS(ata_transfer_data_template, + + TP_PROTO(struct ata_queued_cmd *qc, unsigned int offset, unsigned int count), + + TP_ARGS(qc, offset, count), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __field( unsigned int, ata_dev ) + __field( unsigned int, tag ) + __field( unsigned int, flags ) + __field( unsigned int, offset ) + __field( unsigned int, bytes ) + ), + + TP_fast_assign( + __entry->ata_port = qc->ap->print_id; + __entry->ata_dev = qc->dev->link->pmp + qc->dev->devno; + __entry->tag = qc->tag; + __entry->flags = qc->tf.flags; + __entry->offset = offset; + __entry->bytes = count; + ), + + TP_printk("ata_port=%u ata_dev=%u tag=%d flags=%s offset=%u bytes=%u", + __entry->ata_port, __entry->ata_dev, __entry->tag, + __parse_tf_flags(__entry->flags), + __entry->offset, __entry->bytes) +); + +DEFINE_EVENT(ata_transfer_data_template, ata_sff_pio_transfer_data, + TP_PROTO(struct ata_queued_cmd *qc, unsigned int offset, unsigned int count), + TP_ARGS(qc, offset, count)); + +DEFINE_EVENT(ata_transfer_data_template, atapi_pio_transfer_data, + TP_PROTO(struct ata_queued_cmd *qc, unsigned int offset, unsigned int count), + TP_ARGS(qc, offset, count)); + +DEFINE_EVENT(ata_transfer_data_template, atapi_send_cdb, + TP_PROTO(struct ata_queued_cmd *qc, unsigned int offset, unsigned int count), + TP_ARGS(qc, offset, count)); + +DECLARE_EVENT_CLASS(ata_sff_template, + + TP_PROTO(struct ata_port *ap), + + TP_ARGS(ap), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __field( unsigned char, hsm_state ) + ), + + TP_fast_assign( + __entry->ata_port = ap->print_id; + __entry->hsm_state = ap->hsm_task_state; + ), + + TP_printk("ata_port=%u task_state=%s", + __entry->ata_port, + show_sff_hsm_state_name(__entry->hsm_state)) +); + +DEFINE_EVENT(ata_sff_template, ata_sff_flush_pio_task, + TP_PROTO(struct ata_port *ap), + TP_ARGS(ap)); + #endif /* _TRACE_LIBATA_H */ /* This part must be outside protection */ -- cgit v1.2.3 From c318458c9359ce3d10943b0c15a9b9f43dda7b2e Mon Sep 17 00:00:00 2001 From: Hannes Reinecke Date: Tue, 21 Dec 2021 08:20:34 +0100 Subject: ata: libata: add tracepoints for ATA error handling Add tracepoints for ATA error handling. Signed-off-by: Hannes Reinecke Signed-off-by: Damien Le Moal --- drivers/ata/libata-eh.c | 26 +++++-------------- drivers/ata/libata-pmp.c | 8 ------ drivers/ata/libata-sata.c | 3 --- include/trace/events/libata.h | 60 +++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 67 insertions(+), 30 deletions(-) (limited to 'include/trace') diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c index 043a1c846f2c..69f51616d8bd 100644 --- a/drivers/ata/libata-eh.c +++ b/drivers/ata/libata-eh.c @@ -533,8 +533,6 @@ void ata_scsi_error(struct Scsi_Host *host) unsigned long flags; LIST_HEAD(eh_work_q); - DPRINTK("ENTER\n"); - spin_lock_irqsave(host->host_lock, flags); list_splice_init(&host->eh_cmd_q, &eh_work_q); spin_unlock_irqrestore(host->host_lock, flags); @@ -548,7 +546,6 @@ void ata_scsi_error(struct Scsi_Host *host) /* finish or retry handled scmd's and clean up */ WARN_ON(!list_empty(&eh_work_q)); - DPRINTK("EXIT\n"); } /** @@ -940,7 +937,7 @@ void ata_std_sched_eh(struct ata_port *ap) ata_eh_set_pending(ap, 1); scsi_schedule_eh(ap->scsi_host); - DPRINTK("port EH scheduled\n"); + trace_ata_std_sched_eh(ap); } EXPORT_SYMBOL_GPL(ata_std_sched_eh); @@ -1070,7 +1067,7 @@ static void __ata_port_freeze(struct ata_port *ap) ap->pflags |= ATA_PFLAG_FROZEN; - DPRINTK("ata%u port frozen\n", ap->print_id); + trace_ata_port_freeze(ap); } /** @@ -1147,7 +1144,7 @@ void ata_eh_thaw_port(struct ata_port *ap) spin_unlock_irqrestore(ap->lock, flags); - DPRINTK("ata%u port thawed\n", ap->print_id); + trace_ata_port_thaw(ap); } static void ata_eh_scsidone(struct scsi_cmnd *scmd) @@ -1287,6 +1284,8 @@ void ata_eh_about_to_do(struct ata_link *link, struct ata_device *dev, struct ata_eh_context *ehc = &link->eh_context; unsigned long flags; + trace_ata_eh_about_to_do(link, dev ? dev->devno : 0, action); + spin_lock_irqsave(ap->lock, flags); ata_eh_clear_action(link, dev, ehi, action); @@ -1317,6 +1316,8 @@ void ata_eh_done(struct ata_link *link, struct ata_device *dev, { struct ata_eh_context *ehc = &link->eh_context; + trace_ata_eh_done(link, dev ? dev->devno : 0, action); + ata_eh_clear_action(link, dev, &ehc->i, action); } @@ -1421,8 +1422,6 @@ static void ata_eh_request_sense(struct ata_queued_cmd *qc, return; } - DPRINTK("ATA request sense\n"); - ata_tf_init(dev, &tf); tf.flags |= ATA_TFLAG_ISADDR | ATA_TFLAG_DEVICE; tf.flags |= ATA_TFLAG_LBA | ATA_TFLAG_LBA48; @@ -1463,8 +1462,6 @@ unsigned int atapi_eh_request_sense(struct ata_device *dev, struct ata_port *ap = dev->link->ap; struct ata_taskfile tf; - DPRINTK("ATAPI request sense\n"); - memset(sense_buf, 0, SCSI_SENSE_BUFFERSIZE); /* initialize sense_buf with the error register, @@ -1928,8 +1925,6 @@ static void ata_eh_link_autopsy(struct ata_link *link) u32 serror; int rc; - DPRINTK("ENTER\n"); - if (ehc->i.flags & ATA_EHI_NO_AUTOPSY) return; @@ -2036,7 +2031,6 @@ static void ata_eh_link_autopsy(struct ata_link *link) ehc->i.action |= ata_eh_speed_down(dev, eflags, all_err_mask); trace_ata_eh_link_autopsy(dev, ehc->i.action, all_err_mask); } - DPRINTK("EXIT\n"); } /** @@ -2936,8 +2930,6 @@ static int ata_eh_revalidate_and_attach(struct ata_link *link, unsigned long flags; int rc = 0; - DPRINTK("ENTER\n"); - /* For PATA drive side cable detection to work, IDENTIFY must * be done backwards such that PDIAG- is released by the slave * device before the master device is identified. @@ -3051,7 +3043,6 @@ static int ata_eh_revalidate_and_attach(struct ata_link *link, err: *r_failed_dev = dev; - DPRINTK("EXIT rc=%d\n", rc); return rc; } @@ -3566,8 +3557,6 @@ int ata_eh_recover(struct ata_port *ap, ata_prereset_fn_t prereset, int rc, nr_fails; unsigned long flags, deadline; - DPRINTK("ENTER\n"); - /* prep for recovery */ ata_for_each_link(link, ap, EDGE) { struct ata_eh_context *ehc = &link->eh_context; @@ -3775,7 +3764,6 @@ int ata_eh_recover(struct ata_port *ap, ata_prereset_fn_t prereset, if (rc && r_failed_link) *r_failed_link = link; - DPRINTK("EXIT, rc=%d\n", rc); return rc; } diff --git a/drivers/ata/libata-pmp.c b/drivers/ata/libata-pmp.c index ba7be3f38617..e2e9cbd405fa 100644 --- a/drivers/ata/libata-pmp.c +++ b/drivers/ata/libata-pmp.c @@ -652,8 +652,6 @@ static int sata_pmp_revalidate(struct ata_device *dev, unsigned int new_class) u32 *gscr = (void *)ap->sector_buf; int rc; - DPRINTK("ENTER\n"); - ata_eh_about_to_do(link, NULL, ATA_EH_REVALIDATE); if (!ata_dev_enabled(dev)) { @@ -686,12 +684,10 @@ static int sata_pmp_revalidate(struct ata_device *dev, unsigned int new_class) ata_eh_done(link, NULL, ATA_EH_REVALIDATE); - DPRINTK("EXIT, rc=0\n"); return 0; fail: ata_dev_err(dev, "PMP revalidation failed (errno=%d)\n", rc); - DPRINTK("EXIT, rc=%d\n", rc); return rc; } @@ -759,8 +755,6 @@ static int sata_pmp_eh_recover_pmp(struct ata_port *ap, int detach = 0, rc = 0; int reval_failed = 0; - DPRINTK("ENTER\n"); - if (dev->flags & ATA_DFLAG_DETACH) { detach = 1; rc = -ENODEV; @@ -828,7 +822,6 @@ static int sata_pmp_eh_recover_pmp(struct ata_port *ap, /* okay, PMP resurrected */ ehc->i.flags = 0; - DPRINTK("EXIT, rc=0\n"); return 0; fail: @@ -838,7 +831,6 @@ static int sata_pmp_eh_recover_pmp(struct ata_port *ap, else ata_dev_disable(dev); - DPRINTK("EXIT, rc=%d\n", rc); return rc; } diff --git a/drivers/ata/libata-sata.c b/drivers/ata/libata-sata.c index eddd33a3cb5f..d9b5744a3b06 100644 --- a/drivers/ata/libata-sata.c +++ b/drivers/ata/libata-sata.c @@ -533,8 +533,6 @@ int sata_link_hardreset(struct ata_link *link, const unsigned long *timing, u32 scontrol; int rc; - DPRINTK("ENTER\n"); - if (online) *online = false; @@ -610,7 +608,6 @@ int sata_link_hardreset(struct ata_link *link, const unsigned long *timing, *online = false; ata_link_err(link, "COMRESET failed (errno=%d)\n", rc); } - DPRINTK("EXIT, rc=%d\n", rc); return rc; } EXPORT_SYMBOL_GPL(sata_link_hardreset); diff --git a/include/trace/events/libata.h b/include/trace/events/libata.h index fcb8fde39614..d4e631aa976f 100644 --- a/include/trace/events/libata.h +++ b/include/trace/events/libata.h @@ -490,6 +490,37 @@ TRACE_EVENT(ata_eh_link_autopsy_qc, __parse_eh_err_mask(__entry->eh_err_mask)) ); +DECLARE_EVENT_CLASS(ata_eh_action_template, + + TP_PROTO(struct ata_link *link, unsigned int devno, unsigned int eh_action), + + TP_ARGS(link, devno, eh_action), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + __field( unsigned int, ata_dev ) + __field( unsigned int, eh_action ) + ), + + TP_fast_assign( + __entry->ata_port = link->ap->print_id; + __entry->ata_dev = link->pmp + devno; + __entry->eh_action = eh_action; + ), + + TP_printk("ata_port=%u ata_dev=%u eh_action=%s", + __entry->ata_port, __entry->ata_dev, + __parse_eh_action(__entry->eh_action)) +); + +DEFINE_EVENT(ata_eh_action_template, ata_eh_about_to_do, + TP_PROTO(struct ata_link *link, unsigned int devno, unsigned int eh_action), + TP_ARGS(link, devno, eh_action)); + +DEFINE_EVENT(ata_eh_action_template, ata_eh_done, + TP_PROTO(struct ata_link *link, unsigned int devno, unsigned int eh_action), + TP_ARGS(link, devno, eh_action)); + DECLARE_EVENT_CLASS(ata_link_reset_begin_template, TP_PROTO(struct ata_link *link, unsigned int *class, unsigned long deadline), @@ -570,6 +601,35 @@ DEFINE_EVENT(ata_link_reset_end_template, ata_slave_postreset, TP_PROTO(struct ata_link *link, unsigned int *class, int rc), TP_ARGS(link, class, rc)); +DECLARE_EVENT_CLASS(ata_port_eh_begin_template, + + TP_PROTO(struct ata_port *ap), + + TP_ARGS(ap), + + TP_STRUCT__entry( + __field( unsigned int, ata_port ) + ), + + TP_fast_assign( + __entry->ata_port = ap->print_id; + ), + + TP_printk("ata_port=%u", __entry->ata_port) +); + +DEFINE_EVENT(ata_port_eh_begin_template, ata_std_sched_eh, + TP_PROTO(struct ata_port *ap), + TP_ARGS(ap)); + +DEFINE_EVENT(ata_port_eh_begin_template, ata_port_freeze, + TP_PROTO(struct ata_port *ap), + TP_ARGS(ap)); + +DEFINE_EVENT(ata_port_eh_begin_template, ata_port_thaw, + TP_PROTO(struct ata_port *ap), + TP_ARGS(ap)); + DECLARE_EVENT_CLASS(ata_sff_hsm_template, TP_PROTO(struct ata_queued_cmd *qc, unsigned char status), -- cgit v1.2.3