Skip to content

Instantly share code, notes, and snippets.

@tavplubix
Created September 24, 2020 17:25
Show Gist options
  • Save tavplubix/c7362695fb4afde7227c42bbdbaeb370 to your computer and use it in GitHub Desktop.
Save tavplubix/c7362695fb4afde7227c42bbdbaeb370 to your computer and use it in GitHub Desktop.
https://clickhouse-test-reports.s3.yandex.net/15003/9000ec0331fe062552590d5b253540e5af039b4f/functional_stateless_tests_(release,_polymorphic_parts_enabled).html#fail1
$ grep -Fa "68ca4fdc-77a8-4a80-81bb-d61ad206d16c" clickhouse-server.log
2020.09.24 17:51:04.371695 [ 44982 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loading data parts
2020.09.24 17:51:04.372588 [ 44982 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loaded data parts (0 items)
2020.09.24 17:51:04.492700 [ 44982 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Renaming temporary part tmp_insert_all_1_1_0 to all_1_1_0.
2020.09.24 17:54:31.939489 [ 44977 ] {b46fcd47-6b94-4be4-b12c-769d4f7efec1} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c) (SelectExecutor): Key condition: unknown
2020.09.24 17:54:31.939507 [ 44977 ] {b46fcd47-6b94-4be4-b12c-769d4f7efec1} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c) (SelectExecutor): Not using primary index on part all_1_1_0
2020.09.24 17:54:31.939517 [ 44977 ] {b46fcd47-6b94-4be4-b12c-769d4f7efec1} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c) (SelectExecutor): Selected 1 parts by partition key, 1 parts by primary key, 1 marks by primary key, 1 marks to read from 1 ranges
2020.09.24 17:54:35.192477 [ 34119 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loading data parts
2020.09.24 17:54:35.192998 [ 34119 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loaded data parts (1 items)
2020.09.24 17:54:37.068653 [ 34074 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loading data parts
2020.09.24 17:54:37.069212 [ 34074 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loaded data parts (1 items)
2020.09.24 17:54:38.932384 [ 21562 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loading data parts
2020.09.24 17:54:38.932919 [ 21562 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loaded data parts (1 items)
2020.09.24 17:54:40.745067 [ 34058 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loading data parts
2020.09.24 17:54:40.745516 [ 34058 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loaded data parts (1 items)
2020.09.24 17:54:42.576621 [ 34114 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loading data parts
2020.09.24 17:54:42.577061 [ 34114 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loaded data parts (1 items)
2020.09.24 17:56:10.473254 [ 21668 ] {c0788977-8377-4829-9248-7bbeeb550153} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c) (SelectExecutor): Key condition: unknown
2020.09.24 17:56:10.473272 [ 21668 ] {c0788977-8377-4829-9248-7bbeeb550153} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c) (SelectExecutor): Not using primary index on part all_1_1_0
2020.09.24 17:56:10.473282 [ 21668 ] {c0788977-8377-4829-9248-7bbeeb550153} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c) (SelectExecutor): Selected 1 parts by partition key, 1 parts by primary key, 1 marks by primary key, 1 marks to read from 1 ranges
2020.09.24 17:58:53.993944 [ 46410 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Error> executeQuery: Code: 57, e.displayText() = DB::Exception: Directory for table data store/68c/68ca4fdc-77a8-4a80-81bb-d61ad206d16c/ already exists (version 20.10.1.4749) (from [::1]:49206) (in query: CREATE TABLE local_01099_a (number UInt64) ENGINE = Log; ), Stack trace (when copying this message, always include the lines below):
2020.09.24 17:58:53.994209 [ 46410 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Error> TCPHandler: Code: 57, e.displayText() = DB::Exception: Directory for table data store/68c/68ca4fdc-77a8-4a80-81bb-d61ad206d16c/ already exists, Stack trace:
2020.09.24 18:13:50.092422 [ 241 ] {} <Information> DatabaseCatalog: Will try drop test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c)
2020.09.24 18:13:50.092450 [ 241 ] {} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): dropAllData: waiting for locks.
2020.09.24 18:13:50.092459 [ 241 ] {} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): dropAllData: removing data from memory.
2020.09.24 18:13:50.092468 [ 241 ] {} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): dropAllData: removing data from filesystem.
2020.09.24 18:13:50.092477 [ 241 ] {} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Removing part from filesystem all_1_1_0
2020.09.24 18:13:50.092884 [ 241 ] {} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): dropAllData: done.
2020.09.24 18:13:50.092919 [ 241 ] {} <Information> DatabaseCatalog: Removing metadata /var/lib/clickhouse/metadata_dropped/test_01193_27222.table_9_164.68ca4fdc-77a8-4a80-81bb-d61ad206d16c.sql of dropped table test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c)
$ grep -Fa "2f7f8e82-6c66-4efe-a943-f02f916bd55e" clickhouse-server.log
2020.09.24 17:51:04.139862 [ 44982 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> executeQuery: (from [::1]:39390) CREATE TABLE test_01193_27222.table_9_164 (i UInt64, d Date, s String, n Nested(i UInt8, f Float32)) ENGINE=MergeTree ORDER BY i;
2020.09.24 17:51:04.139961 [ 44982 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Trace> ContextAccess (default): Access granted: CREATE TABLE ON test_01193_27222.table_9_164
2020.09.24 17:51:04.371695 [ 44982 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loading data parts
2020.09.24 17:51:04.372588 [ 44982 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Loaded data parts (0 items)
2020.09.24 17:51:04.491037 [ 44982 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> MemoryTracker: Peak memory usage (for query): 0.00 B.
2020.09.24 17:58:53.982661 [ 46410 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> executeQuery: (from [::1]:49206) CREATE TABLE local_01099_a (number UInt64) ENGINE = Log;
2020.09.24 17:58:53.982754 [ 46410 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Trace> ContextAccess (default): Access granted: CREATE TABLE ON test_wz43oy.local_01099_a
2020.09.24 17:58:53.993944 [ 46410 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Error> executeQuery: Code: 57, e.displayText() = DB::Exception: Directory for table data store/68c/68ca4fdc-77a8-4a80-81bb-d61ad206d16c/ already exists (version 20.10.1.4749) (from [::1]:49206) (in query: CREATE TABLE local_01099_a (number UInt64) ENGINE = Log; ), Stack trace (when copying this message, always include the lines below):
2020.09.24 17:58:53.994209 [ 46410 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Error> TCPHandler: Code: 57, e.displayText() = DB::Exception: Directory for table data store/68c/68ca4fdc-77a8-4a80-81bb-d61ad206d16c/ already exists, Stack trace:
2020.09.24 17:58:53.994275 [ 46410 ] {2f7f8e82-6c66-4efe-a943-f02f916bd55e} <Debug> MemoryTracker: Peak memory usage (for query): 0.00 B.
$ grep -Fa "d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1" clickhouse-server.log
2020.09.24 17:51:04.491473 [ 44982 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Debug> executeQuery: (from [::1]:39390) INSERT INTO test_01193_27222.table_9_164 VALUES
2020.09.24 17:51:04.491588 [ 44982 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Trace> ContextAccess (default): Access granted: INSERT(i, d, s, `n.i`, `n.f`) ON test_01193_27222.table_9_164
2020.09.24 17:51:04.492227 [ 44982 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Debug> DiskLocal: Reserving 1.00 MiB on disk `default`, having unreserved 419.58 GiB.
2020.09.24 17:51:04.492700 [ 44982 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Trace> test_01193_27222.table_9_164 (68ca4fdc-77a8-4a80-81bb-d61ad206d16c): Renaming temporary part tmp_insert_all_1_1_0 to all_1_1_0.
2020.09.24 17:51:04.492796 [ 44982 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Debug> MemoryTracker: Peak memory usage (for query): 0.00 B.
2020.09.24 17:58:54.317372 [ 46410 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Debug> executeQuery: (from [::1]:49222) SELECT * FROM msgpack FORMAT MsgPack
2020.09.24 17:58:54.317823 [ 46410 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Trace> ContextAccess (default): Access granted: SELECT(uint8, uint16, uint32, uint64, int8, int16, int32, int64, float, double, string, date, datetime, datetime64, array) ON test_ou4cj3.msgpack
2020.09.24 17:58:54.317915 [ 46410 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
2020.09.24 17:58:54.318864 [ 46410 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Information> executeQuery: Read 3 rows, 285.00 B in 0.001456167 sec., 2060 rows/sec., 191.13 KiB/sec.
2020.09.24 17:58:54.318903 [ 46410 ] {d3ed15d7-e8f9-4410-b493-eeeb9a5c6ba1} <Debug> MemoryTracker: Peak memory usage (for query): 0.00 B.
$ grep -Fa "[ 44982 ]" clickhouse-server.log | tail -1
2020.09.24 17:54:30.455250 [ 44982 ] {} <Information> TCPHandler: Done processing connection.
$ grep -Fa "[ 46410 ]" clickhouse-server.log | head -1
2020.09.24 17:58:36.855959 [ 46410 ] {} <Trace> TCPHandlerFactory: TCP Request. Address: [::1]:41814
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment