Add log message when stacktrace cannot be obtained for thread

[azat]

Changelog category (leave one):

• Not for changelog (changelog entry is not required)

This is to provide better diagnostics for 01051_system_stack_trace failure 1.

[alexey-milovidov]

Ok.

Caveats:

1. If stack trace in the result is empty - it is already obvious that we cannot obtain it. Why do additional logging with no much details?
2. If it cannot obtain stack trace - usually it cannot do it for all threads - so it will simply write ~1000 useless messages.

[alexey-milovidov]

Ok.

[azat]

If it cannot obtain stack trace - usually it cannot do it for all threads - so it will simply write ~1000 useless messages.

Actually it will not fail for all threads, look:

$ pigz -cd clickhouse-server\ \(5\).log.gz | fgrep -a 034edc75-91b1-4eba-a639-52389b6eaa6e
2021.02.20 12:14:53.707097 [ 74226 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Debug> executeQuery: (from [::1]:37518, using production parser) (comment: /usr/share/clickhouse-test/queries/0_stateless/01051_system_stack_trace.sql) -- at least this query should be present
2021.02.20 12:14:53.711233 [ 74226 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Trace> ContextAccess (default): Access granted: SELECT(query_id) ON system.stack_trace
2021.02.20 12:14:53.846474 [ 74226 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Debug> StorageSystemStackTrace: Cannot obtain a stack trace for thread 1198
2021.02.20 12:14:53.895202 [ 74226 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2021.02.20 12:14:53.899864 [ 308 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Trace> AggregatingTransform: Aggregating
2021.02.20 12:14:53.899996 [ 308 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Trace> Aggregator: Aggregation method: without_key
2021.02.20 12:14:53.900191 [ 308 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Trace> AggregatingTransform: Aggregated. 1 to 1 rows (from 0.00 B) in 0.003031202 sec. (329.90213123374815 rows/sec., 0.00 B/sec.)
2021.02.20 12:14:53.900310 [ 308 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Trace> Aggregator: Merging aggregated data
2021.02.20 12:14:53.902025 [ 74226 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Information> executeQuery: Read 323 rows, 36.62 KiB in 0.194526252 sec., 1660 rows/sec., 188.23 KiB/sec.
2021.02.20 12:14:53.902283 [ 74226 ] {034edc75-91b1-4eba-a639-52389b6eaa6e} <Debug> MemoryTracker: Peak memory usage (for query): 0.00 B.

Fortunately thread 1198 wasn't the thread of the select * from system.stack_trace so the test had been passed.

So it seems that waiting 100ms is too small, and it should be made configurable (and increased in tests)