Skip to content

Commit

Permalink
reader_permit: set_trace_state(): emit trace message linking to previ…
Browse files Browse the repository at this point in the history
…ous page

This method is called on the start of each page, updating the trace
state stored on the permit to that of the current page.
When doing so, emit a trace message, containing the session id of the
previous page, so the per-page sessions can be stiched together later.
Note that this message is only emitted if the cached read
Example:

    Tracing session: dcfc1570-ca3c-11ed-88d0-24443f03a8bb

     activity                                                                                                                              | timestamp                  | source    | source_elapsed | client
    ---------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------
															Execute CQL3 query | 2023-03-24 08:10:27.271000 | 127.0.0.1 |              0 | 127.0.0.1
													     Parsing a statement [shard 0] | 2023-03-24 08:10:27.271864 | 127.0.0.1 |             -- | 127.0.0.1
													  Processing a statement [shard 0] | 2023-03-24 08:10:27.271958 | 127.0.0.1 |             94 | 127.0.0.1
	   Creating read executor for token 3274692326281147944 with all: {127.0.0.1} targets: {127.0.0.1} repair decision: NONE [shard 0] | 2023-03-24 08:10:27.271995 | 127.0.0.1 |            132 | 127.0.0.1
												     read_data: querying locally [shard 0] | 2023-03-24 08:10:27.271998 | 127.0.0.1 |            135 | 127.0.0.1
							     Start querying singular range {{3274692326281147944, pk{00026b73}}} [shard 0] | 2023-03-24 08:10:27.272003 | 127.0.0.1 |            140 | 127.0.0.1
									     [reader concurrency semaphore] admitted immediately [shard 0] | 2023-03-24 08:10:27.272006 | 127.0.0.1 |            143 | 127.0.0.1
										   [reader concurrency semaphore] executing read [shard 0] | 2023-03-24 08:10:27.272014 | 127.0.0.1 |            150 | 127.0.0.1
					 Querying cache for range {{3274692326281147944, pk{00026b73}}} and slice {(-inf, +inf)} [shard 0] | 2023-03-24 08:10:27.272022 | 127.0.0.1 |            159 | 127.0.0.1
     Page stats: 1 partition(s), 0 static row(s) (0 live, 0 dead), 3 clustering row(s) (3 live, 0 dead) and 0 range tombstone(s) [shard 0] | 2023-03-24 08:10:27.272076 | 127.0.0.1 |            212 | 127.0.0.1
								   Caching querier with key ab928e0d-b815-46b7-9a02-1fa2d9549477 [shard 0] | 2023-03-24 08:10:27.272084 | 127.0.0.1 |            221 | 127.0.0.1
														Querying is done [shard 0] | 2023-03-24 08:10:27.272087 | 127.0.0.1 |            224 | 127.0.0.1
											    Done processing - preparing a result [shard 0] | 2023-03-24 08:10:27.272106 | 127.0.0.1 |            242 | 127.0.0.1
															  Request complete | 2023-03-24 08:10:27.271259 | 127.0.0.1 |            259 | 127.0.0.1

    Tracing session: dd3092f0-ca3c-11ed-88d0-24443f03a8bb

     activity                                                                                                                              | timestamp                  | source    | source_elapsed | client
    ---------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------
															Execute CQL3 query | 2023-03-24 08:10:27.615000 | 127.0.0.1 |              0 | 127.0.0.1
													     Parsing a statement [shard 0] | 2023-03-24 08:10:27.615223 | 127.0.0.1 |             -- | 127.0.0.1
													  Processing a statement [shard 0] | 2023-03-24 08:10:27.615310 | 127.0.0.1 |             87 | 127.0.0.1
	   Creating read executor for token 3274692326281147944 with all: {127.0.0.1} targets: {127.0.0.1} repair decision: NONE [shard 0] | 2023-03-24 08:10:27.615346 | 127.0.0.1 |            124 | 127.0.0.1
												     read_data: querying locally [shard 0] | 2023-03-24 08:10:27.615349 | 127.0.0.1 |            126 | 127.0.0.1
							     Start querying singular range {{3274692326281147944, pk{00026b73}}} [shard 0] | 2023-03-24 08:10:27.615352 | 127.0.0.1 |            130 | 127.0.0.1
	  Found cached querier for key ab928e0d-b815-46b7-9a02-1fa2d9549477 and range(s) {{{3274692326281147944, pk{00026b73}}}} [shard 0] | 2023-03-24 08:10:27.615358 | 127.0.0.1 |            135 | 127.0.0.1
														 Reusing querier [shard 0] | 2023-03-24 08:10:27.615362 | 127.0.0.1 |            139 | 127.0.0.1
				   Continuing paged query, previous page's trace session is dcfc1570-ca3c-11ed-88d0-24443f03a8bb [shard 0] | 2023-03-24 08:10:27.615364 | 127.0.0.1 |            141 | 127.0.0.1
										   [reader concurrency semaphore] executing read [shard 0] | 2023-03-24 08:10:27.615371 | 127.0.0.1 |            148 | 127.0.0.1
     Page stats: 1 partition(s), 0 static row(s) (0 live, 0 dead), 1 clustering row(s) (1 live, 0 dead) and 0 range tombstone(s) [shard 0] | 2023-03-24 08:10:27.615385 | 127.0.0.1 |            163 | 127.0.0.1
														Querying is done [shard 0] | 2023-03-24 08:10:27.615583 | 127.0.0.1 |            360 | 127.0.0.1
											    Done processing - preparing a result [shard 0] | 2023-03-24 08:10:27.615730 | 127.0.0.1 |            507 | 127.0.0.1
															  Request complete | 2023-03-24 08:10:27.615518 | 127.0.0.1 |            518 | 127.0.0.1
See the message:
    Continuing paged query, previous page's trace session is dcfc1570-ca3c-11ed-88d0-24443f03a8bb [shard 0] | 2023-03-24 08:10:27.615364 | 127.0.0.1 |            141 | 127.0.0.1

This is a folow-up to scylladb#13255
Refs: scylladb#12781
  • Loading branch information
denesb committed Mar 24, 2023
1 parent e8fb718 commit 3516183
Showing 1 changed file with 4 additions and 0 deletions.
4 changes: 4 additions & 0 deletions reader_concurrency_semaphore.cc
Original file line number Diff line number Diff line change
Expand Up @@ -452,6 +452,10 @@ class reader_permit::impl
}

void set_trace_state(tracing::trace_state_ptr trace_ptr) noexcept {
if (_trace_ptr) {
// Create a continuation trace point
tracing::trace(trace_ptr, "Continuing paged query, previous page's trace session is {}", _trace_ptr->session_id());
}
_trace_ptr = std::move(trace_ptr);
}

Expand Down

0 comments on commit 3516183

Please sign in to comment.