
KIrill
13.07.2017
09:41:40
Хм... у меня было с Collapsed-ом ... И рестарт сервера проблемы не решает? (у меня не лечилось никак ... :( ).

Vladimir
13.07.2017
09:42:04
я рестартовать пока не хочу
потому когда такое будет на проде то это не выход
подожду может кто сталкивался и вылечил

Google

Vladimir
13.07.2017
09:43:39
селекты отрабатывают
SELECT count(value)
FROM Measures
┌─count(value)─┐
│ 6258761860 │
└──────────────┘
1 rows in set. Elapsed: 3.852 sec. Processed 6.26 billion rows, 25.04 GB (1.62 billion rows/s., 6.50 GB/s.)
:)

KIrill
13.07.2017
09:46:16
я рестартовать пока не хочу
Ну ... если с репликой, но не особо страшно. Но да, согласен, не хорошо.
Я пока не смог решить ... при перезапуске сервера стартовали некий пулкотоков, которые пытались, вероятно, что-то исправить, но не могли и сыпали exception-ы. Пока прикопал все стектресы и данные для будущего анализа, как будет время. Пока решил проблему снижением частоты записи (не чаще 1 минуты, лучше 5) и отказался от ReplicatedCollapsedMergeTree, перешел на ReplicatedMergeTree.

Vladimir
13.07.2017
09:49:04
инсерты контролировать не очень удобно когда пишуших машин 5 штук
но спсб за комментарии.
очень надеюсь есть решение потому как выглядит серьезной проблемой если вот так может умирать
рестарт не помог
даже не знаю что делать, не дропать же таблицу


Andrey
13.07.2017
10:00:16
Куча такого
2017.07.13 09:33:10.914379 [ 234 ] <Error> HTTPHandler: Code: 252, e.displayText() = DB::Exception: Too much parts. Merges are processing significantly slower than inserts., e.what() = DB::Exception, Stack trace:
0. clickhouse-server(StackTrace::StackTrace()+0x16) [0x28ae4d6]
1. clickhouse-server(DB::Exception::Exception(std::string const&, int)+0x1f) [0x102a3af]
2. clickhouse-server(DB::MergeTreeData::delayInsertIfNeeded(Poco::Event*)+0x34b) [0x29e487b]
3. clickhouse-server(DB::MergeTreeBlockOutputStream::write(DB::Block const&)+0x29) [0x29c1f79]
4. clickhouse-server(DB::PushingToViewsBlockOutputStream::write(DB::Block const&)+0x486) [0x2b38906]
5. clickhouse-server(DB::MaterializingBlockOutputStream::write(DB::Block const&)+0x28) [0x2b27698]
6. clickhouse-server(DB::AddingDefaultBlockOutputStream::write(DB::Block const&)+0x235) [0x2c6f295]
7. clickhouse-server(DB::ProhibitColumnsBlockOutputStream::write(DB::Block const&)+0x4f) [0x2c892af]
8. clickhouse-server(DB::SquashingBlockOutputStream::finalize()+0x455) [0x2c507f5]
9. clickhouse-server(DB::SquashingBlockOutputStream::writeSuffix()+0x11) [0x2c50981]
10. clickhouse-server(DB::copyData(DB::IBlockInputStream&, DB::IBlockOutputStream&, std::atomic<bool>*)+0x6d9) [0x2af60e9]
11. clickhouse-server(DB::executeQuery(DB::ReadBuffer&, DB::WriteBuffer&, bool, DB::Context&, std::function<void (std::string const&)>)+0x287) [0x282cc57]
12. clickhouse-server(DB::HTTPHandler::processQuery(Poco::Net::HTTPServerRequest&, HTMLForm&, Poco::Net::HTTPServerResponse&, DB::HTTPHandler::Output&)+0x1d31) [0x1033301]
13. clickhouse-server(DB::HTTPHandler::handleRequest(Poco::Net::HTTPServerRequest&, Poco::Net::HTTPServerResponse&)+0x1e5) [0x10353c5]
14. clickhouse-server(Poco::Net::HTTPServerConnection::run()+0x27b) [0x317899b]
15. clickhouse-server(Poco::Net::TCPServerConnection::start()+0xf) [0x315d0af]
16. clickhouse-server(Poco::Net::TCPServerDispatcher::run()+0x10b) [0x317ac3b]
17. clickhouse-server(Poco::PooledThread::run()+0x87) [0x337b807]
18. clickhouse-server(Poco::ThreadImpl::runnableEntry(void*)+0x96) [0x333d456]
19. /lib/x86_64-linux-gnu/libpthread.so.0(+0x8184) [0x7f5a03e86184]
20. /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f5a034a0ffd]
Если я правильно понимаю, то в данном случае куски содаются быстрее чем мержатся. Если остановить инсерты, не оживает?


Vladimir
13.07.2017
10:00:29
нет
в этом то и вопрос
у мен не оживает + system.merges пустая + загрузка процессора 0 - ничего КХ не делает тоесть

Andrey
13.07.2017
10:01:36
А на инсерт какая ошибка? сори если повторяюсь с вопросами

Vladimir
13.07.2017
10:01:45
такая же
вот на клиенте
2017.07.13 09:22:25.558977 [ 225 ] <Error> executeQuery: Code: 252, e.displayText() = DB::Exception: Too much parts. Merges are processing significantly slower than inserts., e.what() = DB::Exception (from 10.159.116.118:35611) (in query: INSERT INTO Measures FORMAT TabSeparated ),
клиента прибил - не ожило

Google

Vladimir
13.07.2017
10:02:27
перестартовал кх не ожило
тупик....

Andrey
13.07.2017
10:02:41
а покажи логи старта


Vladimir
13.07.2017
10:02:49
сек
root@spm-ch-1:/var/log/clickhouse-server# cat clickhouse-server.log
2017.07.13 10:03:40.011228 [ 1 ] <Information> : Starting daemon with revision 54245
2017.07.13 10:03:40.013759 [ 1 ] <Information> Application: starting up
2017.07.13 10:03:40.016546 [ 1 ] <Warning> ConfigProcessor: Include not found: networks
2017.07.13 10:03:40.016572 [ 1 ] <Warning> ConfigProcessor: Include not found: networks
2017.07.13 10:03:40.017043 [ 1 ] <Information> Application: Loading metadata.
2017.07.13 10:03:40.017583 [ 1 ] <Information> DatabaseOrdinary (system): Total 0 tables.
2017.07.13 10:03:40.017596 [ 1 ] <Information> DatabaseOrdinary (system): Starting up tables.
2017.07.13 10:03:40.017894 [ 1 ] <Information> DatabaseOrdinary (default): Total 1 tables.
2017.07.13 10:03:40.018349 [ 2 ] <Information> BackgroundProcessingPool: Create BackgroundProcessingPool with 4 threads
2017.07.13 10:03:40.140136 [ 1 ] <Information> DatabaseOrdinary (default): Starting up tables.
2017.07.13 10:03:40.140291 [ 1 ] <Information> DatabaseOrdinary (monitoring): Total 0 tables.
2017.07.13 10:03:40.140301 [ 1 ] <Information> DatabaseOrdinary (monitoring): Starting up tables.
2017.07.13 10:03:40.140713 [ 1 ] <Information> Application: Listening http://127.0.0.1:8123
2017.07.13 10:03:40.140747 [ 1 ] <Information> Application: Listening tcp: 127.0.0.1:9000
2017.07.13 10:03:40.140772 [ 1 ] <Information> Application: Listening interserver: 127.0.0.1:9009
2017.07.13 10:03:40.140792 [ 1 ] <Information> Application: Listening http://10.147.14.106:8123
2017.07.13 10:03:40.140815 [ 1 ] <Information> Application: Listening tcp: 10.147.14.106:9000
2017.07.13 10:03:40.140834 [ 1 ] <Information> Application: Listening interserver: 10.147.14.106:9009
2017.07.13 10:03:40.141097 [ 1 ] <Information> Application: Available RAM = 29.45 GiB; physical cores = 4; threads = 8.
2017.07.13 10:03:40.141106 [ 1 ] <Information> Application: Ready for connections.
2017.07.13 10:03:42.017086 [ 3 ] <Warning> ConfigProcessor: Include not found: clickhouse_remote_servers
2017.07.13 10:03:42.017176 [ 3 ] <Warning> ConfigProcessor: Include not found: clickhouse_compression
root@spm-ch-1:/var/log/clickhouse-server# cat clickhouse-server.err.log
2017.07.13 10:03:40.016556 [ 1 ] <Warning> ConfigProcessor: Include not found: networks
2017.07.13 10:03:40.016575 [ 1 ] <Warning> ConfigProcessor: Include not found: networks
2017.07.13 10:03:42.017125 [ 3 ] <Warning> ConfigProcessor: Include not found: clickhouse_remote_servers
2017.07.13 10:03:42.017179 [ 3 ] <Warning> ConfigProcessor: Include not found: clickhouse_compression
это все, больше ничего не пишет в логи
сейчас лог в трейс переведу
может подробнее будет


Andrey
13.07.2017
10:07:26
А в /var/lib/clickhouse/data/%database%/%table% много директорий? И какие у них размеры?


Vladimir
13.07.2017
10:09:32
вот с трейсами
2017.07.13 10:08:17.689980 [ 2 ] <Debug> default.Measures (Data): Loading data parts
2017.07.13 10:08:17.810332 [ 2 ] <Debug> default.Measures (Data): Loaded data parts (355 items)
2017.07.13 10:08:17.810953 [ 1 ] <Information> DatabaseOrdinary (default): Starting up tables.
2017.07.13 10:08:17.811085 [ 1 ] <Information> DatabaseOrdinary (monitoring): Total 0 tables.
2017.07.13 10:08:17.811094 [ 1 ] <Information> DatabaseOrdinary (monitoring): Starting up tables.
2017.07.13 10:08:17.811247 [ 1 ] <Debug> Application: Loaded metadata.
355 items мне не нравится, это больше 300 и может оно что-то блочит
root@spm-ch-1:/var/log/clickhouse-server# du -sh /mnt/clickhouse/data/data/default/Measures/* | sort -hr
324M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_71049_71648_3
323M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_153132_153986_5
322M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_70075_70678_3
322M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_132535_133376_5
319M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_55359_56085_3
318M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_50809_51550_3
318M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_106718_107564_3
317M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_131051_131888_5
315M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_39203_39934_3
314M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_79687_80285_3
314M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_103657_104438_3
313M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_54613_55346_3
312M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_8924_9855_4
312M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_140004_140820_5
312M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_127125_127933_5
312M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_102410_103158_3
311M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_92675_93410_3
311M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_41283_41998_3
310M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_62650_63364_3
310M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_15534_16262_3
310M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_144881_145697_5
308M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_35733_36447_3
306M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_34523_35238_3
304M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_111918_112711_4
303M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_152317_153119_5
303M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_126321_127112_5
302M /mnt/clickhouse/data/data/default/Measures/20170710_20170713_137320_138110_5
.....
дирректории 355 как в логе было написано подозреваю
всего 64GB


Andrey
13.07.2017
10:14:28
А если по ней бахнуть OPTIMIZE?
сек гляну доку

Vladimir
13.07.2017
10:15:37
:) OPTIMIZE TABLE Measures
OPTIMIZE TABLE Measures
Ok.
0 rows in set. Elapsed: 3.597 sec.
:)
бахнул
сча поглядим

Google

Andrey
13.07.2017
10:15:56
А если в конце добить FINAL ?))

Vladimir
13.07.2017
10:17:16
Received exception from server:
Code: 36. DB::Exception: Received from localhost:9000, 127.0.0.1. DB::Exception: FINAL flag for OPTIMIZE query is meaningful only with specified PARTITION.
походу надо конкретную партицию указать

Andrey
13.07.2017
10:17:44
да
укажи например июль, судя по логам выше там есть несколько кусков

Vladimir
13.07.2017
10:18:41
да там только июль
это данные за пол дня вчера только
пошло что-то делать

Andrey
13.07.2017
10:25:03
что в system.merges?

Vladimir
13.07.2017
10:25:37
1 rows in set. Elapsed: 0.002 sec.
:)
надежда есть

Andrey
13.07.2017
10:25:57
ну т.е. мерж пошел

Vladimir
13.07.2017
10:26:09
ага

Andrey
13.07.2017
10:26:10
странно почему в один поток если там столько кусков
В голову приходит только ограничение на минимальный размер куска для мержа. Но я не помню как пропертя зовется

Vladimir
13.07.2017
10:27:02
вроде оно в один поток после OPTIMIZE делает
где-то чиьал такое

Павел Максимов
13.07.2017
10:29:30
Привет всем. Я новичок в этой сфере. Гугл не помог, дайте материал пожалуйста, как открыть доступ к файлу на веб сервере ubuntu по веб ссылке. Спасибо!

Bulat
13.07.2017
10:30:21
https://docs.python.org/2/library/simplehttpserver.html

Google

Bulat
13.07.2017
10:30:32
но вообще, фейспалм, конечно)

Vladimir
13.07.2017
10:30:43
:)
Во что в логах
2017.07.13 10:21:09.105769 [ 4 ] <Debug> default.Measures (Merger): Merging 300 parts: from 20170710_20170712_1_971_4 to 20170710_20170713_159284_159284_0 into tmp_merge_20170710_20170713_1_159284_6
может он все 300 штук за раз хочет замержить

Vsevolod
13.07.2017
10:33:31
а вот еще такой вопросик: самому ch есть какая-то разница, вливаю я в него данные через keep-alive соединение или шпарю по коннекту на каждый кусок данных (примерно по 2-3 тыщи записей в каждом, около 2-3 раз в секунду)

Vladimir
13.07.2017
10:33:41
единственное что мержит походу в один поток - весь сервер курит
надо поискать может можно указать сколько потоков использовать
Ну если скорость без keep-alive устраивает то разницы нет

Admin
ERROR: S client not available

Tima
13.07.2017
10:36:38

Andrey
13.07.2017
10:36:41
Мож сервак просто в диски уперся?
пул у тебя судя по логам запуска 4 потока

Vladimir
13.07.2017
10:38:10
Tima Ber -> пасиб
wait<1
SSD диск на амазоне справляется
там в картинке что я выше кидал видно что CPU курит, там и wait видно
да пул 4 потока
но htop говорит что работает 1
осталось 3 вопроса
1. Почему оно не начало мержить само? Получается надо ручками будет запускать.
2. Работает оптимизация долго, как бы это прогресс отслежавать чтобы понять когда можно будет писать потихоньку
3. Пул стоит 4 потока но загружен при оптимизации 1, чего бы подкрутить чтобы ускорить
хотим кх как бекенд релтайм системы и вопросы надо эти решить иначе пользователи не поймут

Google

KIrill
13.07.2017
10:51:05

Vladimir
13.07.2017
10:51:24
не могу пока сказать
он выполняется пока

Andrey
13.07.2017
10:52:27
кусков меньше не стало?


Vladimir
13.07.2017
10:53:01
SELECT count(partition)
FROM system.parts
┌─count(partition)─┐
│ 346 │
└──────────────────┘
1 rows in set. Elapsed: 0.006 sec.
и на этом пока застопорилось
больше запускаться не хочет
:) OPTIMIZE TABLE Measures PARTITION 201707
OPTIMIZE TABLE Measures PARTITION 201707
Ok.
0 rows in set. Elapsed: 0.001 sec.
:) OPTIMIZE TABLE Measures PARTITION 201707 FINAL
OPTIMIZE TABLE Measures PARTITION 201707 FINAL
Ok.
0 rows in set. Elapsed: 0.001 sec.
:) SELECT count(partition) FROM system.parts
SELECT count(partition)
FROM system.parts
┌─count(partition)─┐
│ 346 │
└──────────────────┘
1 rows in set. Elapsed: 0.003 sec.
:)
мерж продолжается
:) SELECT count(*) FROM system.merges
SELECT count(*)
FROM system.merges
┌─count()─┐
│ 1 │
└─────────┘
1 rows in set. Elapsed: 0.001 sec.
:)
во
SELECT rows_read
FROM system.merges
┌──rows_read─┐
│ 2744500224 │
└────────────┘
1 rows in set. Elapsed: 0.001 sec.
получается 2.7 миллиарда прочитали из 6 миллиардов, прогресс хорошо отслеживать
OPTIMIZE закончился
инсерты пошли
инсертим 42000 в секунду
пачками по 50000
поставил background_pool_size в 8 (было 4) и количество parts перестало расти при интенсивной вставке
классно будет если это стабильные настройки для меня


M
13.07.2017
12:20:20
Добрый день,
как лечить такое:
<Error> ZooKeeper: There are 10000 active watches. There must be a leak somewhere.
echo wchs | nc localhost 2181
10 connections watching 49438 paths
Total watches:98093

Vladimir
13.07.2017
12:26:35
https://clickhouse.yandex/docs/en/operations/tips.html#zookeeper

M
13.07.2017
12:27:57
Дада, это видели и настройки пересматривали согласно рекомендациям

Vladimir
13.07.2017
12:28:20
а как часто пишите?