Added tracing functionality

[tomaszrybicki]

Signed-off-by: Tomasz Rybicki tomasz.rybicki@intel.com

---

This change is 

[robertbaldyga]

Reviewed 3 of 12 files at r1.
Reviewable status: 0 of 2 LGTMs obtained

---

inc/ocf_trace.h, line 16 at r1 (raw file):

 * @brief OCF trace (event) type
 */
typedef enum {

Consider unifying literal values to hex only or character only.

---

inc/ocf_trace.h, line 51 at r1 (raw file):

};

static inline void ocf_event_init_hdr(struct ocf_event_hdr *hdr,

Missing doxygen doc.

---

inc/ocf_trace.h, line 78 at r1 (raw file):

	/** Cache size in sectors */
	uint64_t cache_size;

We by default handle all sizes in OCF in bytes. Please change this.

---

inc/ocf_trace.h, line 101 at r1 (raw file):

	/** Core size in sectors */
	uint64_t core_size;

This should also be in bytes.

---

inc/ocf_trace.h, line 117 at r1 (raw file):

	/** Discard */
	ocf_event_io_dir_discard = 'D',
} ocf_event_io_dir_t;

IMO "dir" is kind of unfortunate name in this case. I'd suggest ocf_event_operation_t or ocf_event_op_t.

---

inc/ocf_trace.h, line 127 at r1 (raw file):

	/** Address of IO in sectors */
	uint64_t lba;

In ocf_io we use addr in sectors, and this probably should stay in accordance with this convention.

---

inc/ocf_trace.h, line 130 at r1 (raw file):

	/** Size of IO in sectors */
	uint32_t len;

Also io size is normally expressed in bytes in OCF.

---

inc/ocf_trace.h, line 136 at r1 (raw file):

	/** Core ID */
	uint32_t core_id;

We want to use ocf_core_id_t here.

---

src/ocf_cache_priv.h, line 213 at r1 (raw file):

	void *cleaning_policy_context;

	/* Placeholder for push_event callback */

Please consider creating dedicated structure containing all of the following fields (declare it in ocf_trace.h) and embedding it into ocf_cache. This would help to keep reasonable number of members in ocf_cache structure.

[robertbaldyga]

Reviewed 9 of 12 files at r1.
Reviewable status: 0 of 2 LGTMs obtained

---

src/ocf_core.c, line 438 at r1 (raw file):

	ocf_trace_io(core_io,
			io->dir ? ocf_event_io_dir_wr : ocf_event_io_dir_rd);

We should not assume meaning of numeric io->dir value. Please explicitly compare it with OCF_READ or OCF_WRITE.

---

src/ocf_core.c, line 531 at r1 (raw file):

	ocf_core_update_stats(core, io);

	if (cache->trace_callback)

Use brackets for multiline if() statement.

---

src/ocf_core.c, line 533 at r1 (raw file):

	if (cache->trace_callback)
		ocf_trace_prep_io_event(&trace_event, core_io,
				io->dir ? ocf_event_io_dir_wr : ocf_event_io_dir_rd);

Again, please explicitly compare io->dir with OCF_READ or OCF_WRITE.

---

src/ocf_request.h, line 10 at r1 (raw file):

#include "ocf_env.h"
#include "ocf/ocf_trace.h"

Why do we need this header included if nothing from it is used here?

---

src/ocf_trace.c, line 22 at r1 (raw file):

	struct ocf_event_core_desc core_desc;
	struct core_trace_visitor_ctx *visitor_ctx =
		(struct core_trace_visitor_ctx *) ctx;

Please use two tabs indent when breaking line.

---

src/ocf_trace.c, line 27 at r1 (raw file):

	ocf_event_init_hdr(&core_desc.hdr, ocf_event_type_core_desc,
			ocf_trace_seq_id(cache), env_get_tick_ns(),
			sizeof(core_desc));

No need to break line twice here.

---

src/ocf_trace.c, line 30 at r1 (raw file):

	core_desc.id = ocf_core_get_id(core);
	core_desc.core_size = ocf_data_obj_get_length(
			ocf_core_get_data_object(core)) >> SECTOR_SHIFT;

In general we should use BYTES_TO_SECTORS instead of shifting by SECTOR_SHIFT manually, but I'd rather suggest to change units of core_desc.core_size to bytes.

---

src/ocf_trace.c, line 33 at r1 (raw file):

	ocf_trace_push(cache, visitor_ctx->io_queue,
		&core_desc, sizeof(core_desc));

Again, two tabs indent when breaking line. Please fix this also in other places.

---

src/ocf_trace.c, line 38 at r1 (raw file):

}

static int _ocf_trace_desc(ocf_cache_t cache, uint32_t io_queue)

This function name doesn't describe what it really does.

---

src/ocf_trace.c, line 51 at r1 (raw file):

	cache_desc.cache_mode = ocf_cache_get_mode(cache);
	cache_desc.cache_size = ocf_data_obj_get_length(
		ocf_cache_get_data_object(cache)) >> SECTOR_SHIFT;

Use BYTES_TO_SECTORS() or (preferred option) change units of cache_desc.cache_size to bytes.

---

src/ocf_trace.c, line 61 at r1 (raw file):

	visitor_ctx.io_queue = io_queue;

	retval = ocf_core_visit(cache,

Why break such a short line?

---

src/ocf_trace.c, line 75 at r1 (raw file):

	uint32_t i;

	if (!cache || !trace_callback)

Absence of proper cache pointer almost surely means bug in code, so I suggest using OCF_CHECK_NULL() macro.

---

src/ocf_trace.c, line 83 at r1 (raw file):

	if (cache->trace_callback) {
		ocf_log(cache->owner, log_err,

Please use ocf_cache_log(). Fix this also in other places.

---

src/ocf_trace.c, line 115 at r1 (raw file):

{
	int result, i;
	int32_t timeout_ms = 300;

In some scenarios this timeout might be to short. We probably want to give user option to specify her own value.

---

src/ocf_trace_priv.h, line 36 at r1 (raw file):

		io->timestamp, sizeof(*ev));

	ev->lba = rq->byte_position >> SECTOR_SHIFT;

You can use BYTES_TO_SECTORS(), but preferable solution would be to express event lba address in bytes, to keep it consistent with OCF conventions.

---

src/ocf_trace_priv.h, line 37 at r1 (raw file):

	ev->lba = rq->byte_position >> SECTOR_SHIFT;
	if (ocf_event_io_dir_discard == dir) {

This reversed check looks weird. Contemporary compilers can detect assignment in condition problem.
Additionally you don't need brackets if body of if and else statement has only one line.

---

src/ocf_trace_priv.h, line 52 at r1 (raw file):

	void *trace, uint32_t size)
{
	if (!env_atomic_read(&cache->stop_trace_pending)) {

Using following construction would decrease indent of whole function by single tab:

if (env_atomic_read(&cache->stop_trace_pending))
	return;

---

src/ocf_trace_priv.h, line 55 at r1 (raw file):

		env_atomic64_inc(&cache->io_queues[io_queue].trace_ref_cntr);

		//Double stop_trace_pending flag check prevents from using

Don't use single line comments. Use multi line instead.

[robertbaldyga]

My suggestion is to rebase this on top of current ocf master and squash it into single commit. We probably don't want to have all this commits in repo history.

Reviewable status: 0 of 2 LGTMs obtained

---

src/ocf_core.c, line 438 at r2 (raw file):

	ocf_trace_io(core_io,
			io->dir ? OCF_WRITE : OCF_READ);

That's not exactly what I meant. If we redefine OCF_WRITE to 2 and OCF_READ to 4, then each and every io will be traced as write. That's for sure not what we want. Please fix it also in other places.

---

src/ocf_request.h, line 10 at r2 (raw file):

#include "ocf_env.h"
#include "ocf/ocf_trace.h"

Again, why do we include header which is not used here?

---

src/ocf_trace_priv.h, line 67 at r2 (raw file):

	/* Double stop_trace_pending flag check prevents from using
	   callback when traces are being stopped */

Our comment convention is like:

/*
 * This is my example
 * multiline comment.
 */

[tomaszrybicki]

Reviewable status: 0 of 2 LGTMs obtained

---

inc/ocf_trace.h, line 16 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Consider unifying literal values to hex only or character only.

Done.

---

inc/ocf_trace.h, line 51 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Missing doxygen doc.

Moved to trace_priv.

---

inc/ocf_trace.h, line 78 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

We by default handle all sizes in OCF in bytes. Please change this.

Done.

---

inc/ocf_trace.h, line 101 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

This should also be in bytes.

Done.

---

inc/ocf_trace.h, line 117 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

IMO "dir" is kind of unfortunate name in this case. I'd suggest ocf_event_operation_t or ocf_event_op_t.

Done.

---

inc/ocf_trace.h, line 127 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

In ocf_io we use addr in sectors, and this probably should stay in accordance with this convention.

Done.

---

inc/ocf_trace.h, line 130 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Also io size is normally expressed in bytes in OCF.

Done.

---

inc/ocf_trace.h, line 136 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

We want to use ocf_core_id_t here.

Done.

---

src/ocf_cache_priv.h, line 213 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Please consider creating dedicated structure containing all of the following fields (declare it in ocf_trace.h) and embedding it into ocf_cache. This would help to keep reasonable number of members in ocf_cache structure.

Trace struct definition put in ocf_cache_priv.h

---

src/ocf_core.c, line 438 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

We should not assume meaning of numeric io->dir value. Please explicitly compare it with OCF_READ or OCF_WRITE.

Done.

---

src/ocf_core.c, line 531 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Use brackets for multiline if() statement.

Done.

---

src/ocf_core.c, line 533 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Again, please explicitly compare io->dir with OCF_READ or OCF_WRITE.

Done.

---

src/ocf_core.c, line 438 at r2 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

That's not exactly what I meant. If we redefine OCF_WRITE to 2 and OCF_READ to 4, then each and every io will be traced as write. That's for sure not what we want. Please fix it also in other places.

Done.

---

src/ocf_trace.c, line 22 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Please use two tabs indent when breaking line.

Done.

---

src/ocf_trace.c, line 27 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

No need to break line twice here.

Done.

---

src/ocf_trace.c, line 30 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

In general we should use BYTES_TO_SECTORS instead of shifting by SECTOR_SHIFT manually, but I'd rather suggest to change units of core_desc.core_size to bytes.

Done.

---

src/ocf_trace.c, line 33 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Again, two tabs indent when breaking line. Please fix this also in other places.

Done.

---

src/ocf_trace.c, line 38 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

This function name doesn't describe what it really does.

Done.

---

src/ocf_trace.c, line 51 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Use BYTES_TO_SECTORS() or (preferred option) change units of cache_desc.cache_size to bytes.

Done.

---

src/ocf_trace.c, line 61 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Why break such a short line?

Done.

---

src/ocf_trace.c, line 75 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Absence of proper cache pointer almost surely means bug in code, so I suggest using OCF_CHECK_NULL() macro.

Done.

---

src/ocf_trace.c, line 83 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Please use ocf_cache_log(). Fix this also in other places.

Done.

---

src/ocf_trace.c, line 115 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

In some scenarios this timeout might be to short. We probably want to give user option to specify her own value.

Timeout removed.

---

src/ocf_trace_priv.h, line 36 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

You can use BYTES_TO_SECTORS(), but preferable solution would be to express event lba address in bytes, to keep it consistent with OCF conventions.

Done.

---

src/ocf_trace_priv.h, line 37 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

This reversed check looks weird. Contemporary compilers can detect assignment in condition problem.
Additionally you don't need brackets if body of if and else statement has only one line.

Done.

---

src/ocf_trace_priv.h, line 52 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Using following construction would decrease indent of whole function by single tab:

if (env_atomic_read(&cache->stop_trace_pending))
	return;

Done.

---

src/ocf_trace_priv.h, line 55 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Don't use single line comments. Use multi line instead.

Done.

---

src/ocf_trace_priv.h, line 67 at r2 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Our comment convention is like:

/*
 * This is my example
 * multiline comment.
 */

Done.

---

src/ocf_request.h, line 10 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Why do we need this header included if nothing from it is used here?

Done.

---

src/ocf_request.h, line 10 at r2 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

Again, why do we include header which is not used here?

Done.

[robertbaldyga]

Reviewed 10 of 10 files at r2, 7 of 7 files at r3.
Reviewable status: 1 of 2 LGTMs obtained

[arutk]

Reviewable status: 1 of 2 LGTMs obtained

---

inc/ocf_trace.h, line 132 at r3 (raw file):

	/** Operation type: read, write, trim or flush **/
	ocf_event_operation_t dir;

Since you changed type name from dir to operation_t, I suggest renaming the field to 'operation' / 'op' as well.

---

src/ocf_trace.c, line 52 at r3 (raw file):

	if (ocf_cache_is_device_attached(cache)) {
		/* Detached cache */

*Attached

---

src/ocf_trace_priv.h, line 77 at r3 (raw file):

	env_atomic64_inc(&cache->io_queues[io_queue].trace_ref_cntr);
	ocf_trace_callback_t trace_callback = cache->trace.trace_callback;

I think declaring variables in the middle of scope will trigger compiler warning in Linux kernel.

---

src/ocf_trace_priv.h, line 84 at r3 (raw file):

	 * callback when traces are being stopped
	 */
	if (cache->trace.trace_callback && cache->trace.trace_ctx) {

Since you already have local variables trace_ctx ant trace_callback initialized, you can use them

---

src/ocf_trace_priv.h, line 84 at r3 (raw file):

	 * callback when traces are being stopped
	 */
	if (cache->trace.trace_callback && cache->trace.trace_ctx) {

Reading cache->trace.trace_callback for the second time will most likely be optimized out by compiler and you will get the same value as initial read. You need to make sure second read is not optimized by compiler or CPU and that it is thread safe (simultaneous read and write form two threads). The easiest way would be to replace checking trace_callback pointer with reading atomic variable indicating tracing state (on/off).

[tomaszrybicki]

Reviewable status: 0 of 2 LGTMs obtained, and 1 stale

---

inc/ocf_trace.h, line 132 at r3 (raw file):

Previously, arutk (Adam Rutkowski) wrote…

Since you changed type name from dir to operation_t, I suggest renaming the field to 'operation' / 'op' as well.

Done.

---

src/ocf_trace.c, line 52 at r3 (raw file):

Previously, arutk (Adam Rutkowski) wrote…

*Attached

Done.

---

src/ocf_trace_priv.h, line 77 at r3 (raw file):

Previously, arutk (Adam Rutkowski) wrote…

I think declaring variables in the middle of scope will trigger compiler warning in Linux kernel.

Done.

---

src/ocf_trace_priv.h, line 84 at r3 (raw file):

Previously, arutk (Adam Rutkowski) wrote…

Since you already have local variables trace_ctx ant trace_callback initialized, you can use them

Done.

---

src/ocf_trace_priv.h, line 84 at r3 (raw file):

Previously, arutk (Adam Rutkowski) wrote…

Reading cache->trace.trace_callback for the second time will most likely be optimized out by compiler and you will get the same value as initial read. You need to make sure second read is not optimized by compiler or CPU and that it is thread safe (simultaneous read and write form two threads). The easiest way would be to replace checking trace_callback pointer with reading atomic variable indicating tracing state (on/off).

As discussed

[robertbaldyga]

Reviewable status: 0 of 2 LGTMs obtained, and 1 stale

---

inc/ocf_trace.h, line 127 at r1 (raw file):

Previously, tomaszrybicki (Tomasz Rybicki) wrote…

Done.

I still see that it's expressed in sectors.

[robertbaldyga]

Reviewed 9 of 9 files at r4.
Reviewable status: 0 of 2 LGTMs obtained, and 1 stale

[tomaszrybicki]

Reviewable status: 0 of 2 LGTMs obtained, and 1 stale

---

inc/ocf_trace.h, line 127 at r1 (raw file):

Previously, robertbaldyga (Robert Bałdyga) wrote…

I still see that it's expressed in sectors.

Overlooked renaming and updating comments. Fixed.

[robertbaldyga]

Reviewed 2 of 2 files at r5.
Reviewable status: 1 of 2 LGTMs obtained

[jfckm]

Reviewed 1 of 12 files at r1, 1 of 7 files at r3, 7 of 9 files at r4, 2 of 2 files at r5.
Reviewable status: complete! 2 of 2 LGTMs obtained