| Message ID | 20240209-spi-mem-stats-v1-1-dd1a422fc015@bootlin.com (mailing list archive) |
|---|---|
| State | Superseded |
| Headers | show |
| Series | spi: spi-mem: add statistics support to ->exec_op() calls | expand |
Hi! On Feb 09, 2024 at 14:51:23 +0100, Théo Lebrun wrote: > Current behavior is that spi-mem operations do not increment statistics, > neither per-controller nor per-device, if ->exec_op() is used. For > operations that do NOT use ->exec_op(), stats are increased as the > usual spi_sync() is called. > > The newly implemented spi_mem_add_op_stats() function is strongly > inspired by spi_statistics_add_transfer_stats(); locking logic and > l2len computation comes from there. > > Statistics that are being filled: bytes{,_rx,_tx}, messages, transfers, > errors, timedout, transfer_bytes_histo_*. > > Note about messages & transfers counters: in the fallback to spi_sync() > case, there are from 1 to 4 transfers per message. We only register one > big transfer in the ->exec_op() case as that is closer to reality. Can you please elaborate on this point a bit? To me it feels then that the reported stats in this case will be less than the true value then? > > This patch is NOT touching: > - spi_async, spi_sync, spi_sync_immediate: those counters describe > precise function calls, incrementing them would be lying. I believe > comparing the messages counter to spi_async+spi_sync is a good way > to detect ->exec_op() calls, but I might be missing edge cases > knowledge. > - transfers_split_maxsize: splitting cannot happen if ->exec_op() is > provided. Credit where it's due - This is a very well written and verbose commit message. Just my personal opinion maybe but all this data about testing can go below the tear line in the description? Or somewhere in the kernel docs would also be just fine. (I know we kernel developers consider git log as the best source of documentation :) ) but still.. if you feel like adding ;) No strong opinions there though. > > Testing this patch: > > $ cd /sys/devices/platform/soc > $ find . -type d -path "*spi*" -name statistics > ./2100000.spi/spi_master/spi0/statistics > ./2100000.spi/spi_master/spi0/spi0.0/statistics > $ cd ./2100000.spi/spi_master/spi0/statistics > > $ for f in *; do printf "%s\t" $f; cat $f; done | \ > grep -v transfer_bytes_histo | column -t > bytes 240745444 > bytes_rx 240170907 > bytes_tx 126320 > errors 0 > messages 97354 > spi_async 0 > spi_sync 0 > spi_sync_immediate 0 > timedout 0 > transfers 97354 > transfers_split_maxsize 0 > > Signed-off-by: Théo Lebrun <theo.lebrun@bootlin.com> > --- > drivers/spi/spi-mem.c | 50 +++++++++++++++++++++++++++++++++++++++++++++++++- > 1 file changed, 49 insertions(+), 1 deletion(-) > > diff --git a/drivers/spi/spi-mem.c b/drivers/spi/spi-mem.c > index 2dc8ceb85374..171fe6b1c247 100644 > --- a/drivers/spi/spi-mem.c > +++ b/drivers/spi/spi-mem.c > @@ -297,6 +297,50 @@ static void spi_mem_access_end(struct spi_mem *mem) > pm_runtime_put(ctlr->dev.parent); > } > > +static void spi_mem_add_op_stats(struct spi_statistics __percpu *pcpu_stats, > + const struct spi_mem_op *op, int exec_op_ret) > +{ > + struct spi_statistics *stats; > + int len, l2len; > + > + get_cpu(); > + stats = this_cpu_ptr(pcpu_stats); > + u64_stats_update_begin(&stats->syncp); > + > + /* > + * We do not have the concept of messages or transfers. Let's consider > + * that one operation is equivalent to one message and one transfer. Why 1 message _and_ 1 xfer and not simply 1 xfer? Even in the example of testing that you showed above the values for message and xfer are anyway going to be same, then why have these 2 members in the first place? Can we not do away with one of these? Sorry but I am not too familiar with u64_stats_inc so my q. may sound silly. Seems to be more of a concept widely used in networking side of the kernel. > + */ > + u64_stats_inc(&stats->messages); > + u64_stats_inc(&stats->transfers); > + > + /* Use the sum of all lengths as bytes count and histogram value. */ > + len = (int)op->cmd.nbytes + (int)op->addr.nbytes; > + len += (int)op->dummy.nbytes + (int)op->data.nbytes; > + u64_stats_add(&stats->bytes, len); > + l2len = min(fls(len), SPI_STATISTICS_HISTO_SIZE) - 1; > + l2len = max(l2len, 0); > + u64_stats_inc(&stats->transfer_bytes_histo[l2len]); > + > + /* Only account for data bytes as xferred bytes. */ > + if (op->data.nbytes && op->data.dir == SPI_MEM_DATA_OUT) > + u64_stats_add(&stats->bytes_tx, op->data.nbytes); > + if (op->data.nbytes && op->data.dir == SPI_MEM_DATA_IN) > + u64_stats_add(&stats->bytes_rx, op->data.nbytes); > + > + /* > + * A timeout is not an error, following the same behavior as > + * spi_transfer_one_message(). > + */ > + if (exec_op_ret == -ETIMEDOUT) > + u64_stats_inc(&stats->timedout); > + else if (exec_op_ret) > + u64_stats_inc(&stats->errors); > + > + u64_stats_update_end(&stats->syncp); > + put_cpu(); > +} > + > /** > * spi_mem_exec_op() - Execute a memory operation > * @mem: the SPI memory > @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) > * read path) and expect the core to use the regular SPI > * interface in other cases. > */ > - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) > + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > + Just curious, how much does this impact performance? Have you been able to do some before / after profiling with/out this patch? For eg. for every single spimem op I'm constantly going to incur the penalty of these calls right? Just wondering if we can / should make this optional to have the op_stats. If there is a perf penalty, like if my ospi operations start being impacted by these calls then I may not be okay with this patch. But if you have tested and not found it to be the case I am okay with these changes. If I find some time later, I'll try to test but I'm caught up with some other work. For now I'll leave my R-by with the above conditions addressed / answered. Mostly LGTM, Reviewed-by: Dhruva Gole <d-gole@ti.com>
On Mon, Feb 12, 2024 at 04:43:55PM +0530, Dhruva Gole wrote: > On Feb 09, 2024 at 14:51:23 +0100, Théo Lebrun wrote: > > + /* > > + * We do not have the concept of messages or transfers. Let's consider > > + * that one operation is equivalent to one message and one transfer. > Why 1 message _and_ 1 xfer and not simply 1 xfer? > Even in the example of testing that you showed above the values for > message and xfer are anyway going to be same, then why have these 2 > members in the first place? Can we not do away with one of these? If the device supports regular SPI operations as well as spi-mem operations then this will ensure that the spi-mem stats fit in with the other operations. If it only supports spi-mem operations it would not matter so much.
Hello, On Mon Feb 12, 2024 at 12:13 PM CET, Dhruva Gole wrote: > Hi! > > On Feb 09, 2024 at 14:51:23 +0100, Théo Lebrun wrote: > > Current behavior is that spi-mem operations do not increment statistics, > > neither per-controller nor per-device, if ->exec_op() is used. For > > operations that do NOT use ->exec_op(), stats are increased as the > > usual spi_sync() is called. > > > > The newly implemented spi_mem_add_op_stats() function is strongly > > inspired by spi_statistics_add_transfer_stats(); locking logic and > > l2len computation comes from there. > > > > Statistics that are being filled: bytes{,_rx,_tx}, messages, transfers, > > errors, timedout, transfer_bytes_histo_*. > > > > Note about messages & transfers counters: in the fallback to spi_sync() > > case, there are from 1 to 4 transfers per message. We only register one > > big transfer in the ->exec_op() case as that is closer to reality. > > Can you please elaborate on this point a bit? To me it feels then that > the reported stats in this case will be less than the true value then? To me, a transfer is one transaction with the SPI controller. In most implementations of ->exec_op(), the controller gets configured once for the full transfer to take place. This contrasts with the fallback case that does from 1 to 4 transfers (cmd, addr, dummy & data, with the last three being optional). One transfer feels closer to what happens from my point-of-view. What would be your definition of a transfer? Or the "official" one that the sysfs entry represents? > > This patch is NOT touching: > > - spi_async, spi_sync, spi_sync_immediate: those counters describe > > precise function calls, incrementing them would be lying. I believe > > comparing the messages counter to spi_async+spi_sync is a good way > > to detect ->exec_op() calls, but I might be missing edge cases > > knowledge. > > - transfers_split_maxsize: splitting cannot happen if ->exec_op() is > > provided. > > Credit where it's due - This is a very well written and verbose commit > message. Thanks! > Just my personal opinion maybe but all this data about testing can go > below the tear line in the description? I see where you are coming from. I'll do so on the next revision (if there is one). > Or somewhere in the kernel docs would also be just fine. (I know we > kernel developers consider git log as the best source of documentation > :) ) but still.. if you feel like adding ;) A first step would be to have the sysfs SPI statistics API be described inside Documentation/. That is outside the scope of this patch though. :-) > No strong opinions there though. Same. [...] > > +static void spi_mem_add_op_stats(struct spi_statistics __percpu *pcpu_stats, > > + const struct spi_mem_op *op, int exec_op_ret) > > +{ > > + struct spi_statistics *stats; > > + int len, l2len; > > + > > + get_cpu(); > > + stats = this_cpu_ptr(pcpu_stats); > > + u64_stats_update_begin(&stats->syncp); > > + > > + /* > > + * We do not have the concept of messages or transfers. Let's consider > > + * that one operation is equivalent to one message and one transfer. > > Why 1 message _and_ 1 xfer and not simply 1 xfer? > Even in the example of testing that you showed above the values for > message and xfer are anyway going to be same, then why have these 2 > members in the first place? Can we not do away with one of these? Mark Brown gave an answer to this. Indeed, with regular SPI operations, one message doesn't map to one transfer. [...] > > /** > > * spi_mem_exec_op() - Execute a memory operation > > * @mem: the SPI memory > > @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) > > * read path) and expect the core to use the regular SPI > > * interface in other cases. > > */ > > - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) > > + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > > + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > > + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > > + > > Just curious, how much does this impact performance? Have you been able > to do some before / after profiling with/out this patch? > > For eg. for every single spimem op I'm constantly going to incur the > penalty of these calls right? I have indeed done some benchmarking. I was not able to measure anything significant. Neither doing timings of end-to-end testing by reading loads of data over UBIFS, nor by using ftrace's function_graph. > Just wondering if we can / should make this optional to have the > op_stats. If there is a perf penalty, like if my ospi operations start > being impacted by these calls then I may not be okay with this patch. I've asked myself the same question. It is being done unconditionally on regular SPI ops, so I guess the question has been answered previously: no need to make this conditional. See spi_statistics_add_transfer_stats() in drivers/spi/spi.c. > But if you have tested and not found it to be the case I am okay with > these changes. > > If I find some time later, I'll try to test but I'm caught up with some > other work. For now I'll leave my R-by with the above conditions > addressed / answered. > > Mostly LGTM, > > Reviewed-by: Dhruva Gole <d-gole@ti.com> Thanks for your review! I don't regret adding you to the Cc list. Regards, -- Théo Lebrun, Bootlin Embedded Linux and Kernel engineering https://bootlin.com
Hi, On Feb 12, 2024 at 15:22:41 +0100, Théo Lebrun wrote: > Hello, > > On Mon Feb 12, 2024 at 12:13 PM CET, Dhruva Gole wrote: > > Hi! > > > > On Feb 09, 2024 at 14:51:23 +0100, Théo Lebrun wrote: > > > Current behavior is that spi-mem operations do not increment statistics, > > > neither per-controller nor per-device, if ->exec_op() is used. For > > > operations that do NOT use ->exec_op(), stats are increased as the > > > usual spi_sync() is called. > > > > > > The newly implemented spi_mem_add_op_stats() function is strongly > > > inspired by spi_statistics_add_transfer_stats(); locking logic and > > > l2len computation comes from there. > > > > > > Statistics that are being filled: bytes{,_rx,_tx}, messages, transfers, > > > errors, timedout, transfer_bytes_histo_*. > > > > > > Note about messages & transfers counters: in the fallback to spi_sync() > > > case, there are from 1 to 4 transfers per message. We only register one > > > big transfer in the ->exec_op() case as that is closer to reality. > > > > Can you please elaborate on this point a bit? To me it feels then that > > the reported stats in this case will be less than the true value then? > > To me, a transfer is one transaction with the SPI controller. In most > implementations of ->exec_op(), the controller gets configured once for > the full transfer to take place. This contrasts with the fallback case > that does from 1 to 4 transfers (cmd, addr, dummy & data, with the last > three being optional). > > One transfer feels closer to what happens from my point-of-view. What > would be your definition of a transfer? Or the "official" one that the > sysfs entry represents? Yeah I understand your point, this is something I'd also call as a transaction > > > > This patch is NOT touching: > > > - spi_async, spi_sync, spi_sync_immediate: those counters describe > > > precise function calls, incrementing them would be lying. I believe > > > comparing the messages counter to spi_async+spi_sync is a good way > > > to detect ->exec_op() calls, but I might be missing edge cases > > > knowledge. > > > - transfers_split_maxsize: splitting cannot happen if ->exec_op() is > > > provided. > > > > Credit where it's due - This is a very well written and verbose commit > > message. > > Thanks! > > > Just my personal opinion maybe but all this data about testing can go > > below the tear line in the description? > > I see where you are coming from. I'll do so on the next revision (if > there is one). cool! > > > Or somewhere in the kernel docs would also be just fine. (I know we > > kernel developers consider git log as the best source of documentation > > :) ) but still.. if you feel like adding ;) > > A first step would be to have the sysfs SPI statistics API be described > inside Documentation/. That is outside the scope of this patch > though. :-) > > > No strong opinions there though. > > Same. > > [...] > > > > +static void spi_mem_add_op_stats(struct spi_statistics __percpu *pcpu_stats, > > > + const struct spi_mem_op *op, int exec_op_ret) > > > +{ > > > + struct spi_statistics *stats; > > > + int len, l2len; > > > + > > > + get_cpu(); > > > + stats = this_cpu_ptr(pcpu_stats); > > > + u64_stats_update_begin(&stats->syncp); > > > + > > > + /* > > > + * We do not have the concept of messages or transfers. Let's consider > > > + * that one operation is equivalent to one message and one transfer. > > > > Why 1 message _and_ 1 xfer and not simply 1 xfer? > > Even in the example of testing that you showed above the values for > > message and xfer are anyway going to be same, then why have these 2 > > members in the first place? Can we not do away with one of these? > > Mark Brown gave an answer to this. Indeed, with regular SPI operations, > one message doesn't map to one transfer. Thanks for explaining Mark, understood. > > [...] > > > > /** > > > * spi_mem_exec_op() - Execute a memory operation > > > * @mem: the SPI memory > > > @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) > > > * read path) and expect the core to use the regular SPI > > > * interface in other cases. > > > */ > > > - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) > > > + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > > > + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > > > + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > > > + > > > > Just curious, how much does this impact performance? Have you been able > > to do some before / after profiling with/out this patch? > > > > For eg. for every single spimem op I'm constantly going to incur the > > penalty of these calls right? > > I have indeed done some benchmarking. I was not able to measure anything > significant. Neither doing timings of end-to-end testing by reading > loads of data over UBIFS, nor by using ftrace's function_graph. Awesome. > > > Just wondering if we can / should make this optional to have the > > op_stats. If there is a perf penalty, like if my ospi operations start > > being impacted by these calls then I may not be okay with this patch. > > I've asked myself the same question. It is being done unconditionally on > regular SPI ops, so I guess the question has been answered previously: > no need to make this conditional. > > See spi_statistics_add_transfer_stats() in drivers/spi/spi.c. Yeah I did see that, but maybe it didn't occur then whether we should make it optional. Anyway, I'm ok with this too. Let's worry about optional in future if required. > > > But if you have tested and not found it to be the case I am okay with > > these changes. > > > > If I find some time later, I'll try to test but I'm caught up with some > > other work. For now I'll leave my R-by with the above conditions > > addressed / answered. > > > > Mostly LGTM, > > > > Reviewed-by: Dhruva Gole <d-gole@ti.com> > > Thanks for your review! I don't regret adding you to the Cc list. > Cheers!
On 2/9/24 13:51, Théo Lebrun wrote: > Current behavior is that spi-mem operations do not increment statistics, > neither per-controller nor per-device, if ->exec_op() is used. For > operations that do NOT use ->exec_op(), stats are increased as the > usual spi_sync() is called. > > The newly implemented spi_mem_add_op_stats() function is strongly > inspired by spi_statistics_add_transfer_stats(); locking logic and > l2len computation comes from there. > > Statistics that are being filled: bytes{,_rx,_tx}, messages, transfers, > errors, timedout, transfer_bytes_histo_*. > > Note about messages & transfers counters: in the fallback to spi_sync() > case, there are from 1 to 4 transfers per message. We only register one > big transfer in the ->exec_op() case as that is closer to reality. > > This patch is NOT touching: > - spi_async, spi_sync, spi_sync_immediate: those counters describe > precise function calls, incrementing them would be lying. I believe > comparing the messages counter to spi_async+spi_sync is a good way > to detect ->exec_op() calls, but I might be missing edge cases > knowledge. > - transfers_split_maxsize: splitting cannot happen if ->exec_op() is > provided. > > Testing this patch: > > $ cd /sys/devices/platform/soc > $ find . -type d -path "*spi*" -name statistics > ./2100000.spi/spi_master/spi0/statistics > ./2100000.spi/spi_master/spi0/spi0.0/statistics > $ cd ./2100000.spi/spi_master/spi0/statistics > > $ for f in *; do printf "%s\t" $f; cat $f; done | \ > grep -v transfer_bytes_histo | column -t > bytes 240745444 > bytes_rx 240170907 > bytes_tx 126320 > errors 0 > messages 97354 > spi_async 0 > spi_sync 0 > spi_sync_immediate 0 > timedout 0 > transfers 97354 > transfers_split_maxsize 0 > > Signed-off-by: Théo Lebrun <theo.lebrun@bootlin.com> > --- > drivers/spi/spi-mem.c | 50 +++++++++++++++++++++++++++++++++++++++++++++++++- > 1 file changed, 49 insertions(+), 1 deletion(-) > > diff --git a/drivers/spi/spi-mem.c b/drivers/spi/spi-mem.c > index 2dc8ceb85374..171fe6b1c247 100644 > --- a/drivers/spi/spi-mem.c > +++ b/drivers/spi/spi-mem.c > @@ -297,6 +297,50 @@ static void spi_mem_access_end(struct spi_mem *mem) > pm_runtime_put(ctlr->dev.parent); > } > > +static void spi_mem_add_op_stats(struct spi_statistics __percpu *pcpu_stats, > + const struct spi_mem_op *op, int exec_op_ret) > +{ > + struct spi_statistics *stats; > + int len, l2len; > + > + get_cpu(); > + stats = this_cpu_ptr(pcpu_stats); > + u64_stats_update_begin(&stats->syncp); > + > + /* > + * We do not have the concept of messages or transfers. Let's consider > + * that one operation is equivalent to one message and one transfer. > + */ > + u64_stats_inc(&stats->messages); > + u64_stats_inc(&stats->transfers); > + > + /* Use the sum of all lengths as bytes count and histogram value. */ > + len = (int)op->cmd.nbytes + (int)op->addr.nbytes; > + len += (int)op->dummy.nbytes + (int)op->data.nbytes; spi_mem_check_op() makes sure that op->cmd.nbytes != 0, otherwise it returns -EINVAL ... > + u64_stats_add(&stats->bytes, len); > + l2len = min(fls(len), SPI_STATISTICS_HISTO_SIZE) - 1; ... thus l2len can never be negative. You can declare len and l2len as u64. The casts from above shall disappear. > + l2len = max(l2len, 0); > + u64_stats_inc(&stats->transfer_bytes_histo[l2len]); > + > + /* Only account for data bytes as xferred bytes. */ s/xferred/transferred? > + if (op->data.nbytes && op->data.dir == SPI_MEM_DATA_OUT) > + u64_stats_add(&stats->bytes_tx, op->data.nbytes); > + if (op->data.nbytes && op->data.dir == SPI_MEM_DATA_IN) > + u64_stats_add(&stats->bytes_rx, op->data.nbytes); > + > + /* > + * A timeout is not an error, following the same behavior as > + * spi_transfer_one_message(). > + */ > + if (exec_op_ret == -ETIMEDOUT) > + u64_stats_inc(&stats->timedout); > + else if (exec_op_ret) > + u64_stats_inc(&stats->errors); > + > + u64_stats_update_end(&stats->syncp); > + put_cpu(); > +} > + > /** > * spi_mem_exec_op() - Execute a memory operation > * @mem: the SPI memory > @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) > * read path) and expect the core to use the regular SPI > * interface in other cases. > */ > - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) > + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > + Would be good to be able to opt out the statistics if one wants it. SPI NORs can write with a single write op maximum page_size bytes, which is typically 256 bytes. And since there are SPI NORs that can run at 400 MHz, I guess some performance penalty shouldn't be excluded. > return ret; > + } > } > > tmpbufsize = op->cmd.nbytes + op->addr.nbytes + op->dummy.nbytes; > > --- > base-commit: 19b50f80b3a4865bd477aa5c026dd234d39a50d2 > change-id: 20240209-spi-mem-stats-ff9bf91c0f7e > > Best regards,
Hello Tudor, On Tue Feb 13, 2024 at 1:39 PM CET, Tudor Ambarus wrote: > > /** > > * spi_mem_exec_op() - Execute a memory operation > > * @mem: the SPI memory > > @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) > > * read path) and expect the core to use the regular SPI > > * interface in other cases. > > */ > > - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) > > + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > > + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > > + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > > + > > Would be good to be able to opt out the statistics if one wants it. > > SPI NORs can write with a single write op maximum page_size bytes, which > is typically 256 bytes. And since there are SPI NORs that can run at 400 > MHz, I guess some performance penalty shouldn't be excluded. I did my testing on a 40 MHz octal SPI NOR with most reads being much bigger than 256 bytes, so I probably didn't have the fastest setup indeed. What shape would that take? A spi-mem DT prop? New field in the SPI statistics sysfs directory? Other remarks have been taken into account, thanks! -- Théo Lebrun, Bootlin Embedded Linux and Kernel engineering https://bootlin.com
On Tue, Feb 13, 2024 at 12:39:02PM +0000, Tudor Ambarus wrote: > On 2/9/24 13:51, Théo Lebrun wrote: > > + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > > + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > > + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > > + > Would be good to be able to opt out the statistics if one wants it. > SPI NORs can write with a single write op maximum page_size bytes, which > is typically 256 bytes. And since there are SPI NORs that can run at 400 > MHz, I guess some performance penalty shouldn't be excluded. If we can cope with this sort of statistics collection in the networking fast path we can probably cope with it for SPI too, the immediate recording is all per CPU so I'd like to see some numbers showing that it's a problem before worrying about it too much. Even the people doing things like saturating CAN buses haven't been raising it as a concern for the regular SPI data path. We could add a Kconfig if it's an issue.
On 2/13/24 15:28, Mark Brown wrote: > On Tue, Feb 13, 2024 at 12:39:02PM +0000, Tudor Ambarus wrote: >> On 2/9/24 13:51, Théo Lebrun wrote: > >>> + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { >>> + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); >>> + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); >>> + > >> Would be good to be able to opt out the statistics if one wants it. > >> SPI NORs can write with a single write op maximum page_size bytes, which >> is typically 256 bytes. And since there are SPI NORs that can run at 400 >> MHz, I guess some performance penalty shouldn't be excluded. > > If we can cope with this sort of statistics collection in the networking > fast path we can probably cope with it for SPI too, the immediate > recording is all per CPU so I'd like to see some numbers showing that > it's a problem before worrying about it too much. Even the people doing > things like saturating CAN buses haven't been raising it as a concern > for the regular SPI data path. We could add a Kconfig if it's an issue. Ok, we can deal with it afterwards if it'll become an issue.
On 2/13/24 15:00, Théo Lebrun wrote: > Hello Tudor, Hi! > > On Tue Feb 13, 2024 at 1:39 PM CET, Tudor Ambarus wrote: >>> /** >>> * spi_mem_exec_op() - Execute a memory operation >>> * @mem: the SPI memory >>> @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) >>> * read path) and expect the core to use the regular SPI >>> * interface in other cases. >>> */ >>> - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) >>> + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { >>> + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); >>> + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); >>> + >> >> Would be good to be able to opt out the statistics if one wants it. >> >> SPI NORs can write with a single write op maximum page_size bytes, which >> is typically 256 bytes. And since there are SPI NORs that can run at 400 >> MHz, I guess some performance penalty shouldn't be excluded. > > I did my testing on a 40 MHz octal SPI NOR with most reads being much > bigger than 256 bytes, so I probably didn't have the fastest setup > indeed. yeah, reads are bigger, the entire flash can be read with a single read op. > > What shape would that take? A spi-mem DT prop? New field in the SPI > statistics sysfs directory? > I think I'd go with a sysfs entry, it provides flexibility. But I guess we can worry about this if we have some numbers, and I don't have, so you're fine even without the opt-out option. > Other remarks have been taken into account, thanks! > Ok, thanks. Cheers, ta
Hello, On Wed Feb 14, 2024 at 9:00 AM CET, Tudor Ambarus wrote: > On 2/13/24 15:00, Théo Lebrun wrote: > > On Tue Feb 13, 2024 at 1:39 PM CET, Tudor Ambarus wrote: > >>> /** > >>> * spi_mem_exec_op() - Execute a memory operation > >>> * @mem: the SPI memory > >>> @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) > >>> * read path) and expect the core to use the regular SPI > >>> * interface in other cases. > >>> */ > >>> - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) > >>> + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > >>> + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > >>> + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > >>> + > >> > >> Would be good to be able to opt out the statistics if one wants it. > >> > >> SPI NORs can write with a single write op maximum page_size bytes, which > >> is typically 256 bytes. And since there are SPI NORs that can run at 400 > >> MHz, I guess some performance penalty shouldn't be excluded. > > > > I did my testing on a 40 MHz octal SPI NOR with most reads being much > > bigger than 256 bytes, so I probably didn't have the fastest setup > > indeed. > > yeah, reads are bigger, the entire flash can be read with a single read op. > > > > > What shape would that take? A spi-mem DT prop? New field in the SPI > > statistics sysfs directory? > > > > I think I'd go with a sysfs entry, it provides flexibility. But I guess > we can worry about this if we have some numbers, and I don't have, so > you're fine even without the opt-out option. Some ftrace numbers: - 48002 calls to spi_mem_add_op_stats(); - min 1.053000µs; - avg 1.175652µs; - max 16.272000µs. Platform is Mobileye EyeQ5. Cores are Imagine Technologies I6500-F. I don't know the precision of our timer but we might be getting close to what is measurable. Thanks, -- Théo Lebrun, Bootlin Embedded Linux and Kernel engineering https://bootlin.com
On 2/14/24 08:51, Théo Lebrun wrote: > Hello, Hi, Théo, > > On Wed Feb 14, 2024 at 9:00 AM CET, Tudor Ambarus wrote: >> On 2/13/24 15:00, Théo Lebrun wrote: >>> On Tue Feb 13, 2024 at 1:39 PM CET, Tudor Ambarus wrote: >>>>> /** >>>>> * spi_mem_exec_op() - Execute a memory operation >>>>> * @mem: the SPI memory >>>>> @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) >>>>> * read path) and expect the core to use the regular SPI >>>>> * interface in other cases. >>>>> */ >>>>> - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) >>>>> + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { >>>>> + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); >>>>> + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); >>>>> + >>>> >>>> Would be good to be able to opt out the statistics if one wants it. >>>> >>>> SPI NORs can write with a single write op maximum page_size bytes, which >>>> is typically 256 bytes. And since there are SPI NORs that can run at 400 >>>> MHz, I guess some performance penalty shouldn't be excluded. >>> >>> I did my testing on a 40 MHz octal SPI NOR with most reads being much >>> bigger than 256 bytes, so I probably didn't have the fastest setup >>> indeed. >> >> yeah, reads are bigger, the entire flash can be read with a single read op. >> >>> >>> What shape would that take? A spi-mem DT prop? New field in the SPI >>> statistics sysfs directory? >>> >> >> I think I'd go with a sysfs entry, it provides flexibility. But I guess >> we can worry about this if we have some numbers, and I don't have, so >> you're fine even without the opt-out option. > > Some ftrace numbers: > - 48002 calls to spi_mem_add_op_stats(); > - min 1.053000µs; > - avg 1.175652µs; > - max 16.272000µs. > > Platform is Mobileye EyeQ5. Cores are Imagine Technologies I6500-F. I > don't know the precision of our timer but we might be getting close to > what is measurable. > Thanks. I took a random SPI NOR flash [1], its page program typical time is 64µs according to its SFDP data. We'll have to add here the delay the software handling takes. If you want to play a bit more, you can write the entire flash then compare the ftrace numbers of spi_mem_add_op_stats() with spi_nor_write(). Cheers, ta [1] https://ww1.microchip.com/downloads/en/DeviceDoc/20005119G.pdf
On Wed Feb 14, 2024 at 10:29 AM CET, Tudor Ambarus wrote: > On 2/14/24 08:51, Théo Lebrun wrote: > > On Wed Feb 14, 2024 at 9:00 AM CET, Tudor Ambarus wrote: > >> On 2/13/24 15:00, Théo Lebrun wrote: > >>> On Tue Feb 13, 2024 at 1:39 PM CET, Tudor Ambarus wrote: > >>>>> /** > >>>>> * spi_mem_exec_op() - Execute a memory operation > >>>>> * @mem: the SPI memory > >>>>> @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) > >>>>> * read path) and expect the core to use the regular SPI > >>>>> * interface in other cases. > >>>>> */ > >>>>> - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) > >>>>> + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { > >>>>> + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); > >>>>> + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); > >>>>> + > >>>> > >>>> Would be good to be able to opt out the statistics if one wants it. > >>>> > >>>> SPI NORs can write with a single write op maximum page_size bytes, which > >>>> is typically 256 bytes. And since there are SPI NORs that can run at 400 > >>>> MHz, I guess some performance penalty shouldn't be excluded. > >>> > >>> I did my testing on a 40 MHz octal SPI NOR with most reads being much > >>> bigger than 256 bytes, so I probably didn't have the fastest setup > >>> indeed. > >> > >> yeah, reads are bigger, the entire flash can be read with a single read op. > >> > >>> > >>> What shape would that take? A spi-mem DT prop? New field in the SPI > >>> statistics sysfs directory? > >>> > >> > >> I think I'd go with a sysfs entry, it provides flexibility. But I guess > >> we can worry about this if we have some numbers, and I don't have, so > >> you're fine even without the opt-out option. > > > > Some ftrace numbers: > > - 48002 calls to spi_mem_add_op_stats(); > > - min 1.053000µs; > > - avg 1.175652µs; > > - max 16.272000µs. > > > > Platform is Mobileye EyeQ5. Cores are Imagine Technologies I6500-F. I > > don't know the precision of our timer but we might be getting close to > > what is measurable. > > > Thanks. > > I took a random SPI NOR flash [1], its page program typical time is 64µs > according to its SFDP data. We'll have to add here the delay the > software handling takes. > > If you want to play a bit more, you can write the entire flash then > compare the ftrace numbers of spi_mem_add_op_stats() with spi_nor_write(). It is unclear to me why you are focusing on writes? Won't reads be much faster in the common case, and therefore where stats overhead would show the most? For cadence-qspi, only issuing command reads (reads below 8 bytes) would be a sort of pathological case. Thanks, -- Théo Lebrun, Bootlin Embedded Linux and Kernel engineering https://bootlin.com
On 2/14/24 10:59, Théo Lebrun wrote: > On Wed Feb 14, 2024 at 10:29 AM CET, Tudor Ambarus wrote: >> On 2/14/24 08:51, Théo Lebrun wrote: >>> On Wed Feb 14, 2024 at 9:00 AM CET, Tudor Ambarus wrote: >>>> On 2/13/24 15:00, Théo Lebrun wrote: >>>>> On Tue Feb 13, 2024 at 1:39 PM CET, Tudor Ambarus wrote: >>>>>>> /** >>>>>>> * spi_mem_exec_op() - Execute a memory operation >>>>>>> * @mem: the SPI memory >>>>>>> @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) >>>>>>> * read path) and expect the core to use the regular SPI >>>>>>> * interface in other cases. >>>>>>> */ >>>>>>> - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) >>>>>>> + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { >>>>>>> + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); >>>>>>> + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); >>>>>>> + >>>>>> >>>>>> Would be good to be able to opt out the statistics if one wants it. >>>>>> >>>>>> SPI NORs can write with a single write op maximum page_size bytes, which >>>>>> is typically 256 bytes. And since there are SPI NORs that can run at 400 >>>>>> MHz, I guess some performance penalty shouldn't be excluded. >>>>> >>>>> I did my testing on a 40 MHz octal SPI NOR with most reads being much >>>>> bigger than 256 bytes, so I probably didn't have the fastest setup >>>>> indeed. >>>> >>>> yeah, reads are bigger, the entire flash can be read with a single read op. >>>> >>>>> >>>>> What shape would that take? A spi-mem DT prop? New field in the SPI >>>>> statistics sysfs directory? >>>>> >>>> >>>> I think I'd go with a sysfs entry, it provides flexibility. But I guess >>>> we can worry about this if we have some numbers, and I don't have, so >>>> you're fine even without the opt-out option. >>> >>> Some ftrace numbers: >>> - 48002 calls to spi_mem_add_op_stats(); >>> - min 1.053000µs; >>> - avg 1.175652µs; >>> - max 16.272000µs. >>> >>> Platform is Mobileye EyeQ5. Cores are Imagine Technologies I6500-F. I >>> don't know the precision of our timer but we might be getting close to >>> what is measurable. >>> >> Thanks. >> >> I took a random SPI NOR flash [1], its page program typical time is 64µs >> according to its SFDP data. We'll have to add here the delay the >> software handling takes. >> >> If you want to play a bit more, you can write the entire flash then >> compare the ftrace numbers of spi_mem_add_op_stats() with spi_nor_write(). > > It is unclear to me why you are focusing on writes? Won't reads be much It's easier to test as the SPI NOR core will issue a new page program operation, thus a new exec_op() call, for each page size. > faster in the common case, and therefore where stats overhead would > show the most? For cadence-qspi, only issuing command reads (reads below > 8 bytes) would be a sort of pathological case. If you can serialize the reads and do small 8 bytes requests, then yes, small reads are the critical case. Not sure how common it is and how to test it. Again, opting out is not a hard requirement from my side, you're fine with how the patch is now. But if you want to measure the impact, you can either compare with small reads, as you suggested, and with full flash write, where the exec_op() calls will be split by the core on a page_size basis. Cheers, ta
diff --git a/drivers/spi/spi-mem.c b/drivers/spi/spi-mem.c index 2dc8ceb85374..171fe6b1c247 100644 --- a/drivers/spi/spi-mem.c +++ b/drivers/spi/spi-mem.c @@ -297,6 +297,50 @@ static void spi_mem_access_end(struct spi_mem *mem) pm_runtime_put(ctlr->dev.parent); } +static void spi_mem_add_op_stats(struct spi_statistics __percpu *pcpu_stats, + const struct spi_mem_op *op, int exec_op_ret) +{ + struct spi_statistics *stats; + int len, l2len; + + get_cpu(); + stats = this_cpu_ptr(pcpu_stats); + u64_stats_update_begin(&stats->syncp); + + /* + * We do not have the concept of messages or transfers. Let's consider + * that one operation is equivalent to one message and one transfer. + */ + u64_stats_inc(&stats->messages); + u64_stats_inc(&stats->transfers); + + /* Use the sum of all lengths as bytes count and histogram value. */ + len = (int)op->cmd.nbytes + (int)op->addr.nbytes; + len += (int)op->dummy.nbytes + (int)op->data.nbytes; + u64_stats_add(&stats->bytes, len); + l2len = min(fls(len), SPI_STATISTICS_HISTO_SIZE) - 1; + l2len = max(l2len, 0); + u64_stats_inc(&stats->transfer_bytes_histo[l2len]); + + /* Only account for data bytes as xferred bytes. */ + if (op->data.nbytes && op->data.dir == SPI_MEM_DATA_OUT) + u64_stats_add(&stats->bytes_tx, op->data.nbytes); + if (op->data.nbytes && op->data.dir == SPI_MEM_DATA_IN) + u64_stats_add(&stats->bytes_rx, op->data.nbytes); + + /* + * A timeout is not an error, following the same behavior as + * spi_transfer_one_message(). + */ + if (exec_op_ret == -ETIMEDOUT) + u64_stats_inc(&stats->timedout); + else if (exec_op_ret) + u64_stats_inc(&stats->errors); + + u64_stats_update_end(&stats->syncp); + put_cpu(); +} + /** * spi_mem_exec_op() - Execute a memory operation * @mem: the SPI memory @@ -339,8 +383,12 @@ int spi_mem_exec_op(struct spi_mem *mem, const struct spi_mem_op *op) * read path) and expect the core to use the regular SPI * interface in other cases. */ - if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) + if (!ret || ret != -ENOTSUPP || ret != -EOPNOTSUPP) { + spi_mem_add_op_stats(ctlr->pcpu_statistics, op, ret); + spi_mem_add_op_stats(mem->spi->pcpu_statistics, op, ret); + return ret; + } } tmpbufsize = op->cmd.nbytes + op->addr.nbytes + op->dummy.nbytes;
Current behavior is that spi-mem operations do not increment statistics, neither per-controller nor per-device, if ->exec_op() is used. For operations that do NOT use ->exec_op(), stats are increased as the usual spi_sync() is called. The newly implemented spi_mem_add_op_stats() function is strongly inspired by spi_statistics_add_transfer_stats(); locking logic and l2len computation comes from there. Statistics that are being filled: bytes{,_rx,_tx}, messages, transfers, errors, timedout, transfer_bytes_histo_*. Note about messages & transfers counters: in the fallback to spi_sync() case, there are from 1 to 4 transfers per message. We only register one big transfer in the ->exec_op() case as that is closer to reality. This patch is NOT touching: - spi_async, spi_sync, spi_sync_immediate: those counters describe precise function calls, incrementing them would be lying. I believe comparing the messages counter to spi_async+spi_sync is a good way to detect ->exec_op() calls, but I might be missing edge cases knowledge. - transfers_split_maxsize: splitting cannot happen if ->exec_op() is provided. Testing this patch: $ cd /sys/devices/platform/soc $ find . -type d -path "*spi*" -name statistics ./2100000.spi/spi_master/spi0/statistics ./2100000.spi/spi_master/spi0/spi0.0/statistics $ cd ./2100000.spi/spi_master/spi0/statistics $ for f in *; do printf "%s\t" $f; cat $f; done | \ grep -v transfer_bytes_histo | column -t bytes 240745444 bytes_rx 240170907 bytes_tx 126320 errors 0 messages 97354 spi_async 0 spi_sync 0 spi_sync_immediate 0 timedout 0 transfers 97354 transfers_split_maxsize 0 Signed-off-by: Théo Lebrun <theo.lebrun@bootlin.com> --- drivers/spi/spi-mem.c | 50 +++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 49 insertions(+), 1 deletion(-) --- base-commit: 19b50f80b3a4865bd477aa5c026dd234d39a50d2 change-id: 20240209-spi-mem-stats-ff9bf91c0f7e Best regards,