Message ID | 20170424044544.23810-2-benh@kernel.crashing.org |
---|---|
State | Accepted |
Headers | show |
Reviewed-by: Oliver O'Halloran <oohall@gmail.com> On Mon, Apr 24, 2017 at 2:45 PM, Benjamin Herrenschmidt <benh@kernel.crashing.org> wrote: > Log more registers, cleanup the output alignment, > and timestamp start/stop of requests > > Signed-off-by: Benjamin Herrenschmidt <benh@kernel.crashing.org> > --- > hw/p8-i2c.c | 46 +++++++++++++++++++++++++++++++--------------- > 1 file changed, 31 insertions(+), 15 deletions(-) > > diff --git a/hw/p8-i2c.c b/hw/p8-i2c.c > index 2216635..52520dd 100644 > --- a/hw/p8-i2c.c > +++ b/hw/p8-i2c.c > @@ -229,10 +229,10 @@ struct p8_i2c_request { > }; > > static void p8_i2c_print_debug_info(struct p8_i2c_master_port *port, > - struct i2c_request *req) > + struct i2c_request *req, uint64_t end_time) > { > struct p8_i2c_master *master = port->master; > - uint64_t cmd, mode, stat, estat, intr; > + uint64_t cmd, mode, stat, estat, intm, intc; > int rc; > > /* Print master and request structure bits */ > @@ -247,6 +247,10 @@ static void p8_i2c_print_debug_info(struct p8_i2c_master_port *port, > req->dev_addr, req->offset_bytes, req->offset, > req->rw_len); > > + log_simple_error(&e_info(OPAL_RC_I2C_TRANSFER), "I2C: " > + " start_time=%016llx end_time=%016llx (duration=%016llx)\n", > + master->start_time, end_time, end_time - master->start_time); > + > /* Dump the current state of i2c registers */ > rc = xscom_read(master->chip_id, master->xscom_base + I2C_CMD_REG, > &cmd); > @@ -277,16 +281,23 @@ static void p8_i2c_print_debug_info(struct p8_i2c_master_port *port, > } > > rc = xscom_read(master->chip_id, master->xscom_base + I2C_INTR_MASK_REG, > - &intr); > + &intm); > if (rc) { > prlog(PR_DEBUG, "I2C: Failed to read INTR_MASK_REG\n"); > - intr = 0ull; > + intm = 0ull; > + } > + > + rc = xscom_read(master->chip_id, master->xscom_base + I2C_INTR_COND_REG, > + &intc); > + if (rc) { > + prlog(PR_DEBUG, "I2C: Failed to read INTR_COND_REG\n"); > + intc = 0ull; > } > > log_simple_error(&e_info(OPAL_RC_I2C_TRANSFER), "I2C: Register dump--\n" > - "cmd:0x%016llx\tmode:0x%016llx\tstat:0x%016llx\n" > - "estat:0x%016llx\tintr:0x%016llx\n", cmd, mode, stat, > - estat, intr); > + " cmd:0x%016llx\tmode:0x%016llx\tstat:0x%016llx\n" > + " estat:0x%016llx\tintm:0x%016llx\tintc:0x%016llx\n", > + cmd, mode, stat, estat, intm, intc); > } > > static bool p8_i2c_has_irqs(struct p8_i2c_master *master) > @@ -618,7 +629,7 @@ static int p8_i2c_reset_engine(struct p8_i2c_master *master) > > static void p8_i2c_status_error(struct p8_i2c_master_port *port, > struct i2c_request *req, > - uint64_t status) > + uint64_t status, uint64_t end_time) > { > struct p8_i2c_master *master = port->master; > int rc; > @@ -630,7 +641,7 @@ static void p8_i2c_status_error(struct p8_i2c_master_port *port, > if (!(status & (I2C_STAT_NACK_RCVD_ERR | I2C_STAT_PSEUDO_TIMEOUT))) { > log_simple_error(&e_info(OPAL_RC_I2C_TRANSFER), > "I2C: Transfer error occurred\n"); > - p8_i2c_print_debug_info(port, req); > + p8_i2c_print_debug_info(port, req, end_time); > } > > p8_i2c_translate_error(req, status); > @@ -826,12 +837,15 @@ static void p8_i2c_complete_offset(struct p8_i2c_master *master, > } > > static void p8_i2c_status_cmd_completion(struct p8_i2c_master *master, > - struct i2c_request *req) > + struct i2c_request *req, > + uint64_t end_time __unused) > { > int rc; > > DBG("Command completion, state=%d bytes_sent=%d\n", > master->state, master->bytes_sent); > + DBG(" start_time=%016llx end_time=%016llx (duration=%016llx)\n", > + master->start_time, end_time, end_time - master->start_time); > > /* If we complete an offset, we probably need to transition > * do a data read, check if that all makes sense > @@ -858,7 +872,7 @@ static void p8_i2c_check_status(struct p8_i2c_master *master) > { > struct p8_i2c_master_port *port; > struct i2c_request *req; > - uint64_t status; > + uint64_t status, now = mftb(); > int rc; > > /* If we are idle, just return, we'll catch error conditions > @@ -913,11 +927,11 @@ static void p8_i2c_check_status(struct p8_i2c_master *master) > /* Mask status to avoid some unrelated bit overwriting > * our pseudo-status "timeout" bit 63 > */ > - p8_i2c_status_error(port, req, status & I2C_STAT_ANY_ERR); > + p8_i2c_status_error(port, req, status & I2C_STAT_ANY_ERR, now); > } else if (status & I2C_STAT_DATA_REQ) > p8_i2c_status_data_request(master, req, status); > else if (status & I2C_STAT_CMD_COMP) > - p8_i2c_status_cmd_completion(master, req); > + p8_i2c_status_cmd_completion(master, req, now); > } > > static int p8_i2c_check_initial_status(struct p8_i2c_master_port *port) > @@ -1093,6 +1107,8 @@ static int p8_i2c_start_request(struct p8_i2c_master *master, > } > DBG("Command: %016llx, state: %d\n", cmd, master->state); > > + master->start_time = mftb(); > + > /* Send command */ > rc = xscom_write(master->chip_id, master->xscom_base + I2C_CMD_REG, > cmd); > @@ -1272,10 +1288,10 @@ static void p8_i2c_timeout(struct timer *t __unused, void *data, uint64_t now) > /* Allright, we have a request and it has timed out ... */ > log_simple_error(&e_info(OPAL_RC_I2C_TIMEOUT), > "I2C: Request timeout !\n"); > - p8_i2c_print_debug_info(port, req); > + p8_i2c_print_debug_info(port, req, now); > > /* Use the standard error path */ > - p8_i2c_status_error(port, req, I2C_STAT_PSEUDO_TIMEOUT); > + p8_i2c_status_error(port, req, I2C_STAT_PSEUDO_TIMEOUT, now); > exit: > unlock(&master->lock); > } > -- > 2.9.3 > > _______________________________________________ > Skiboot mailing list > Skiboot@lists.ozlabs.org > https://lists.ozlabs.org/listinfo/skiboot
diff --git a/hw/p8-i2c.c b/hw/p8-i2c.c index 2216635..52520dd 100644 --- a/hw/p8-i2c.c +++ b/hw/p8-i2c.c @@ -229,10 +229,10 @@ struct p8_i2c_request { }; static void p8_i2c_print_debug_info(struct p8_i2c_master_port *port, - struct i2c_request *req) + struct i2c_request *req, uint64_t end_time) { struct p8_i2c_master *master = port->master; - uint64_t cmd, mode, stat, estat, intr; + uint64_t cmd, mode, stat, estat, intm, intc; int rc; /* Print master and request structure bits */ @@ -247,6 +247,10 @@ static void p8_i2c_print_debug_info(struct p8_i2c_master_port *port, req->dev_addr, req->offset_bytes, req->offset, req->rw_len); + log_simple_error(&e_info(OPAL_RC_I2C_TRANSFER), "I2C: " + " start_time=%016llx end_time=%016llx (duration=%016llx)\n", + master->start_time, end_time, end_time - master->start_time); + /* Dump the current state of i2c registers */ rc = xscom_read(master->chip_id, master->xscom_base + I2C_CMD_REG, &cmd); @@ -277,16 +281,23 @@ static void p8_i2c_print_debug_info(struct p8_i2c_master_port *port, } rc = xscom_read(master->chip_id, master->xscom_base + I2C_INTR_MASK_REG, - &intr); + &intm); if (rc) { prlog(PR_DEBUG, "I2C: Failed to read INTR_MASK_REG\n"); - intr = 0ull; + intm = 0ull; + } + + rc = xscom_read(master->chip_id, master->xscom_base + I2C_INTR_COND_REG, + &intc); + if (rc) { + prlog(PR_DEBUG, "I2C: Failed to read INTR_COND_REG\n"); + intc = 0ull; } log_simple_error(&e_info(OPAL_RC_I2C_TRANSFER), "I2C: Register dump--\n" - "cmd:0x%016llx\tmode:0x%016llx\tstat:0x%016llx\n" - "estat:0x%016llx\tintr:0x%016llx\n", cmd, mode, stat, - estat, intr); + " cmd:0x%016llx\tmode:0x%016llx\tstat:0x%016llx\n" + " estat:0x%016llx\tintm:0x%016llx\tintc:0x%016llx\n", + cmd, mode, stat, estat, intm, intc); } static bool p8_i2c_has_irqs(struct p8_i2c_master *master) @@ -618,7 +629,7 @@ static int p8_i2c_reset_engine(struct p8_i2c_master *master) static void p8_i2c_status_error(struct p8_i2c_master_port *port, struct i2c_request *req, - uint64_t status) + uint64_t status, uint64_t end_time) { struct p8_i2c_master *master = port->master; int rc; @@ -630,7 +641,7 @@ static void p8_i2c_status_error(struct p8_i2c_master_port *port, if (!(status & (I2C_STAT_NACK_RCVD_ERR | I2C_STAT_PSEUDO_TIMEOUT))) { log_simple_error(&e_info(OPAL_RC_I2C_TRANSFER), "I2C: Transfer error occurred\n"); - p8_i2c_print_debug_info(port, req); + p8_i2c_print_debug_info(port, req, end_time); } p8_i2c_translate_error(req, status); @@ -826,12 +837,15 @@ static void p8_i2c_complete_offset(struct p8_i2c_master *master, } static void p8_i2c_status_cmd_completion(struct p8_i2c_master *master, - struct i2c_request *req) + struct i2c_request *req, + uint64_t end_time __unused) { int rc; DBG("Command completion, state=%d bytes_sent=%d\n", master->state, master->bytes_sent); + DBG(" start_time=%016llx end_time=%016llx (duration=%016llx)\n", + master->start_time, end_time, end_time - master->start_time); /* If we complete an offset, we probably need to transition * do a data read, check if that all makes sense @@ -858,7 +872,7 @@ static void p8_i2c_check_status(struct p8_i2c_master *master) { struct p8_i2c_master_port *port; struct i2c_request *req; - uint64_t status; + uint64_t status, now = mftb(); int rc; /* If we are idle, just return, we'll catch error conditions @@ -913,11 +927,11 @@ static void p8_i2c_check_status(struct p8_i2c_master *master) /* Mask status to avoid some unrelated bit overwriting * our pseudo-status "timeout" bit 63 */ - p8_i2c_status_error(port, req, status & I2C_STAT_ANY_ERR); + p8_i2c_status_error(port, req, status & I2C_STAT_ANY_ERR, now); } else if (status & I2C_STAT_DATA_REQ) p8_i2c_status_data_request(master, req, status); else if (status & I2C_STAT_CMD_COMP) - p8_i2c_status_cmd_completion(master, req); + p8_i2c_status_cmd_completion(master, req, now); } static int p8_i2c_check_initial_status(struct p8_i2c_master_port *port) @@ -1093,6 +1107,8 @@ static int p8_i2c_start_request(struct p8_i2c_master *master, } DBG("Command: %016llx, state: %d\n", cmd, master->state); + master->start_time = mftb(); + /* Send command */ rc = xscom_write(master->chip_id, master->xscom_base + I2C_CMD_REG, cmd); @@ -1272,10 +1288,10 @@ static void p8_i2c_timeout(struct timer *t __unused, void *data, uint64_t now) /* Allright, we have a request and it has timed out ... */ log_simple_error(&e_info(OPAL_RC_I2C_TIMEOUT), "I2C: Request timeout !\n"); - p8_i2c_print_debug_info(port, req); + p8_i2c_print_debug_info(port, req, now); /* Use the standard error path */ - p8_i2c_status_error(port, req, I2C_STAT_PSEUDO_TIMEOUT); + p8_i2c_status_error(port, req, I2C_STAT_PSEUDO_TIMEOUT, now); exit: unlock(&master->lock); }
Log more registers, cleanup the output alignment, and timestamp start/stop of requests Signed-off-by: Benjamin Herrenschmidt <benh@kernel.crashing.org> --- hw/p8-i2c.c | 46 +++++++++++++++++++++++++++++++--------------- 1 file changed, 31 insertions(+), 15 deletions(-)