diff --git a/src/Interpreters/Session.cpp b/src/Interpreters/Session.cpp index f0bb339e278..64f7b4fc934 100644 --- a/src/Interpreters/Session.cpp +++ b/src/Interpreters/Session.cpp @@ -107,7 +107,7 @@ public: if (it == sessions.end()) { if (throw_if_not_found) - throw Exception(ErrorCodes::SESSION_NOT_FOUND, "Session not found."); + throw Exception(ErrorCodes::SESSION_NOT_FOUND, "Session {} not found", session_id); /// Create a new session from current context. auto context = Context::createCopy(global_context); @@ -129,7 +129,7 @@ public: LOG_TEST(log, "Reuse session from storage with session_id: {}, user_id: {}", key.second, key.first); if (!session.unique()) - throw Exception(ErrorCodes::SESSION_IS_LOCKED, "Session is locked by a concurrent client."); + throw Exception(ErrorCodes::SESSION_IS_LOCKED, "Session {} is locked by a concurrent client", session_id); return {session, false}; } } diff --git a/src/Storages/RocksDB/StorageEmbeddedRocksDB.cpp b/src/Storages/RocksDB/StorageEmbeddedRocksDB.cpp index 9ff0c152399..20839982ec3 100644 --- a/src/Storages/RocksDB/StorageEmbeddedRocksDB.cpp +++ b/src/Storages/RocksDB/StorageEmbeddedRocksDB.cpp @@ -276,7 +276,7 @@ void StorageEmbeddedRocksDB::mutate(const MutationCommands & commands, ContextPt assert(commands.front().type == MutationCommand::Type::UPDATE); if (commands.front().column_to_update_expression.contains(primary_key)) - throw Exception(ErrorCodes::BAD_ARGUMENTS, "Primary key cannot be updated"); + throw Exception(ErrorCodes::BAD_ARGUMENTS, "Primary key cannot be updated (cannot update column {})", primary_key); auto interpreter = std::make_unique( storage_ptr, metadata_snapshot, commands, context_, /*can_execute_*/ true, /*return_all_columns*/ true); diff --git a/src/Storages/StorageKeeperMap.cpp b/src/Storages/StorageKeeperMap.cpp index f570f132463..5f7726e11bf 100644 --- a/src/Storages/StorageKeeperMap.cpp +++ b/src/Storages/StorageKeeperMap.cpp @@ -827,7 +827,7 @@ void StorageKeeperMap::mutate(const MutationCommands & commands, ContextPtr loca assert(commands.front().type == MutationCommand::Type::UPDATE); if (commands.front().column_to_update_expression.contains(primary_key)) - throw Exception(ErrorCodes::BAD_ARGUMENTS, "Primary key cannot be updated"); + throw Exception(ErrorCodes::BAD_ARGUMENTS, "Primary key cannot be updated (cannot update column {})", primary_key); auto interpreter = std::make_unique( storage_ptr, metadata_snapshot, commands, local_context, /*can_execute_*/ true, /*return_all_columns*/ true); diff --git a/tests/clickhouse-test b/tests/clickhouse-test index 9067a8142bc..e0d51638593 100755 --- a/tests/clickhouse-test +++ b/tests/clickhouse-test @@ -2076,7 +2076,10 @@ def reportLogStats(args): 'AST is too deep. Maximum: {}', 'Array sizes are too large: {}', 'Unable to connect to HDFS: {}', 'Shutdown is called for table', 'File is not inside {}', 'Table {} doesn''t exist', 'Database {} doesn''t exist', 'Table {}.{} doesn''t exist', - 'File {} doesn''t exist', 'No such attribute ''{}''', 'User name ''{}'' is reserved' + 'File {} doesn''t exist', 'No such attribute ''{}''', 'User name ''{}'' is reserved', + 'Could not find table: {}', 'Detached part "{}" not found', 'Unknown data type family: {}', + 'Unknown input format {}', 'Cannot UPDATE key column {}', 'Substitution {} is not set', + 'Cannot OPTIMIZE table: {}', 'User name is empty', 'Table name is empty', 'AST is too big. Maximum: {}' ) AS known_short_messages SELECT count() AS c, message_format_string, substr(any(message), 1, 120) FROM system.text_log @@ -2084,7 +2087,7 @@ def reportLogStats(args): AND (length(message_format_string) < 16 OR (length(message_format_string) < 30 AND message ilike '%DB::Exception%')) AND message_format_string NOT IN known_short_messages - GROUP BY message_format_string ORDER BY c DESC LIMIT 30 FORMAT TSVWithNamesAndTypes + GROUP BY message_format_string ORDER BY c DESC LIMIT 50 FORMAT TSVWithNamesAndTypes """ value = clickhouse_execute(args, query).decode(errors="replace") print("\nTop short messages:\n") diff --git a/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.reference b/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.reference index fddfbd49de3..60ac6e30c59 100644 --- a/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.reference +++ b/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.reference @@ -1,8 +1,8 @@ runtime messages 0.001 runtime exceptions 0.05 -messages shorter than 10 10 -messages shorter than 16 40 -exceptions shorter than 30 120 +messages shorter than 10 0 +messages shorter than 16 2 +exceptions shorter than 30 40 noisy messages 0.3 noisy Trace messages 0.16 noisy Debug messages 0.09 diff --git a/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.sql b/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.sql index 71f41c7a9d2..b9269b66ff7 100644 --- a/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.sql +++ b/tests/queries/0_stateless/00002_log_and_exception_messages_formatting.sql @@ -14,14 +14,43 @@ select 'runtime messages', max2(coalesce(sum(length(message_format_string) = 0) -- Check the same for exceptions. The value was 0.03 select 'runtime exceptions', max2(coalesce(sum(length(message_format_string) = 0) / countOrNull(), 0), 0.05) from logs where message like '%DB::Exception%'; +-- FIXME some of the following messages are not informative and it has to be fixed +create temporary table known_short_messages (s String) as select * from (select +['', '({}) Keys: {}', '({}) {}', 'Aggregating', 'Became leader', 'Cleaning queue', 'Creating set.', +'Cyclic aliases', 'Detaching {}', 'Executing {}', 'Fire events: {}', 'Found part {}', 'Loaded queue', +'No sharding key', 'No tables', 'Query: {}', 'Removed', 'Removed part {}', 'Removing parts.', +'Request URI: {}', 'Sending part {}', 'Sent handshake', 'Starting {}', 'Will mimic {}', 'Writing to {}', +'dropIfEmpty', 'loadAll {}', '{} ({}:{})', '{} -> {}', '{} {}', '{}: {}', 'Query was cancelled', +'Table {} already exists.', '{}%', 'Cancelled merging parts', 'All replicas are lost', +'Cancelled mutating parts', 'Read object: {}', 'New segment: {}', 'Unknown geometry type {}', +'Table {} is not replicated', '{} {}.{} already exists', 'Attempt to read after eof', +'Replica {} already exists', 'Convert overflow', 'key must be a tuple', 'Division by zero', +'No part {} in committed state', 'Files set to {}', 'Bytes set to {}', 'Sharding key {} is not used', +'Cannot parse datetime', 'Bad get: has {}, requested {}', 'There is no {} in {}', 'Numeric overflow', +'Polygon is not valid: {}', 'Decimal math overflow', '{} only accepts maps', 'Dictionary ({}) not found', +'Unknown format {}', 'Invalid IPv4 value', 'Invalid IPv6 value', 'Unknown setting {}', +'Unknown table function {}', 'Database {} already exists.', 'Table {} doesn''t exist', +'Invalid credentials', 'Part {} already exists', 'Invalid mode: {}', 'Log pulling is cancelled', +'JOIN {} cannot get JOIN keys', 'Unknown function {}{}', 'Cannot parse IPv6 {}', +'Not found address of host: {}', '{} must contain a tuple', 'Unknown codec family: {}', +'Expected const String column', 'Invalid partition format: {}', 'Cannot parse IPv4 {}', +'AST is too deep. Maximum: {}', 'Array sizes are too large: {}', 'Unable to connect to HDFS: {}', +'Shutdown is called for table', 'File is not inside {}', +'Table {} doesn''t exist', 'Database {} doesn''t exist', 'Table {}.{} doesn''t exist', +'File {} doesn''t exist', 'No such attribute ''{}''', 'User name ''{}'' is reserved', +'Could not find table: {}', 'Detached part "{}" not found', 'Unknown data type family: {}', +'Unknown input format {}', 'Cannot UPDATE key column {}', 'Substitution {} is not set', +'Cannot OPTIMIZE table: {}', 'User name is empty', 'Table name is empty', 'AST is too big. Maximum: {}' +] as arr) array join arr; + -- Check that we don't have too many short meaningless message patterns. -select 'messages shorter than 10', max2(countDistinctOrDefault(message_format_string), 10) from logs where length(message_format_string) < 10; +select 'messages shorter than 10', max2(countDistinctOrDefault(message_format_string), 0) from logs where length(message_format_string) < 10 and message_format_string not in known_short_messages; -- Same as above. Feel free to update the threshold or remove this query if really necessary -select 'messages shorter than 16', max2(countDistinctOrDefault(message_format_string), 40) from logs where length(message_format_string) < 16; +select 'messages shorter than 16', max2(countDistinctOrDefault(message_format_string), 2) from logs where length(message_format_string) < 16 and message_format_string not in known_short_messages; -- Same as above, but exceptions must be more informative. Feel free to update the threshold or remove this query if really necessary -select 'exceptions shorter than 30', max2(countDistinctOrDefault(message_format_string), 120) from logs where length(message_format_string) < 30 and message ilike '%DB::Exception%'; +select 'exceptions shorter than 30', max2(countDistinctOrDefault(message_format_string), 40) from logs where length(message_format_string) < 30 and message ilike '%DB::Exception%' and message_format_string not in known_short_messages; -- Avoid too noisy messages: top 1 message frequency must be less than 30%. We should reduce the threshold diff --git a/tests/queries/0_stateless/00463_long_sessions_in_http_interface.sh b/tests/queries/0_stateless/00463_long_sessions_in_http_interface.sh index 89da84a5bdd..35e75c9ec4e 100755 --- a/tests/queries/0_stateless/00463_long_sessions_in_http_interface.sh +++ b/tests/queries/0_stateless/00463_long_sessions_in_http_interface.sh @@ -8,7 +8,7 @@ CURDIR=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd) echo "Using non-existent session with the 'session_check' flag will throw exception:" -${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&session_id=nonexistent&session_check=1" --data-binary "SELECT 1" | grep -c -F 'Session not found' +${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&session_id=nonexistent&session_check=1" --data-binary "SELECT 1" | grep -c -F 'SESSION_NOT_FOUND' echo "Using non-existent session without the 'session_check' flag will create a new session:" ${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&session_id=${CLICKHOUSE_DATABASE}_1" --data-binary "SELECT 1" @@ -30,7 +30,7 @@ ${CLICKHOUSE_CLIENT} --multiquery --query "DROP USER IF EXISTS test_00463; CREAT ${CLICKHOUSE_CURL} -sS -X POST "${CLICKHOUSE_URL}&session_id=${CLICKHOUSE_DATABASE}_6&session_timeout=600" --data-binary "CREATE TEMPORARY TABLE t (s String)" ${CLICKHOUSE_CURL} -sS -X POST "${CLICKHOUSE_URL}&session_id=${CLICKHOUSE_DATABASE}_6" --data-binary "INSERT INTO t VALUES ('Hello')" -${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&user=test_00463&session_id=${CLICKHOUSE_DATABASE}_6&session_check=1" --data-binary "SELECT 1" | grep -c -F 'Session not found' +${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&user=test_00463&session_id=${CLICKHOUSE_DATABASE}_6&session_check=1" --data-binary "SELECT 1" | grep -c -F 'SESSION_NOT_FOUND' ${CLICKHOUSE_CURL} -sS -X POST "${CLICKHOUSE_URL}&user=test_00463&session_id=${CLICKHOUSE_DATABASE}_6&session_timeout=600" --data-binary "CREATE TEMPORARY TABLE t (s String)" ${CLICKHOUSE_CURL} -sS -X POST "${CLICKHOUSE_URL}&user=test_00463&session_id=${CLICKHOUSE_DATABASE}_6" --data-binary "INSERT INTO t VALUES ('World')" @@ -53,7 +53,7 @@ do ${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&session_id=${CLICKHOUSE_DATABASE}_7&session_timeout=1" --data-binary "SELECT 1" ${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&session_id=${CLICKHOUSE_DATABASE}_7&session_check=1" --data-binary "SELECT 1" sleep 3 - ${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&session_id=${CLICKHOUSE_DATABASE}_7&session_check=1" --data-binary "SELECT 1" | grep -c -F 'Session not found' + ${CLICKHOUSE_CURL} -sS "${CLICKHOUSE_URL}&session_id=${CLICKHOUSE_DATABASE}_7&session_check=1" --data-binary "SELECT 1" | grep -c -F 'SESSION_NOT_FOUND' ) | tr -d '\n' | grep -F '111' && break || sleep 1 done