Телеграмм чат группы tarantoolru страница 7738

оно похоже могло зациклиться на парсинге

похоже на то
хотя мне ещё не нравится состояние буфера

11:41пожаловаться #1

Michael Filonenko in Tarantool

Добавил строку source ./third_party/luajit/src/luajit-gdb.py в файл .gdbinit.
Похоже нормально подключается дополнение, в стектрейсе есть об этом инфа.
Визуально стектрейс особенно не изменился.
Оговорюсь - опыта отладки на таком уровне у меня нет. На данный момент больше догадки: по ощущениям тарантул бесконечно парсит http ответ.
Для проверки попробовал отключить сеть. То-есть фактически http запросы и ответы не могут уходить/приходить. Но поведение tarantool не меняется, продолжает писать в трейсе тоже самое.
Трейс прикладываю.

для успокоения в открытом gdb вот сделайте

lj-stack
lj-stack 0x4058f020

это покажет lua стек, ну мало ли вы там найдет вайл тру

11:43пожаловаться #2

Запускаю так:

gdb -ex "generate-core-file" -p 1169082

(gdb) lj-stack
0x41f37f08:0x41f37f28 [    ] 5 slots: Red zone
0x41f37f00            [   M]
0x41f37d80:0x41f37ef8 [    ] 48 slots: Free stack slots
0x41f37d78            [  T ]
0x41f37d70            [S   ] FRAME: dummy L

(gdb) lj-stack 0x4058f020
0x405a0430:0x405a0450 [    ] 5 slots: Red zone
0x405a0428            [   M]
0x405a0318:0x405a0420 [    ] 34 slots: Free stack slots
0x405a0310            [  T ]
0x405a0308            [    ] VALUE: table @ 0x4059f120 (asize: 0, hmask: 0x1)
0x405a0300            [    ] VALUE: string "headers" @ 0x40c35a18
0x405a02f8            [    ] VALUE: table @ 0x4059f090 (asize: 0, hmask: 0x1)
0x405a02f0            [    ] VALUE: table @ 0x40d31950 (asize: 0, hmask: 0x1)
0x405a02e8            [    ] VALUE: nil
0x405a02e0            [    ] VALUE: string "http://10.9.7.170:8080/energomera/?VOLTA()" @ 0x40d1e3d8
0x405a02d8            [    ] VALUE: string "GET" @ 0x410539a8
0x405a02d0            [ B  ] VALUE: userdata @ 0x414f6ce0
0x405a02c8            [    ] FRAME: [M] delta=8, C function @ 0x5daf80
0x405a02c0            [    ] VALUE: number 174320.00000037957
0x405a02b8            [    ] VALUE: trace 0x67 @ 0x4069fb58
0x405a02b0            [    ] VALUE: table @ 0x40d31950 (asize: 0, hmask: 0x1)
0x405a02a8            [    ] VALUE: nil
0x405a02a0            [    ] VALUE: string "http://10.9.7.170:8080/energomera/?VOLTA()" @ 0x40d1e3d8
0x405a0298            [    ] VALUE: string "GET" @ 0x410539a8
0x405a0290            [    ] VALUE: table @ 0x414f85c0 (asize: 0, hmask: 0x1)
0x405a0288            [    ] FRAME: [LP] delta=6, Lua function @ 0x41048b38, 2 upvalues, "@builtin/http.client.lua":316
0x405a0280            [    ] VALUE: string "http://10.9.7.170:8080/energomera/?VOLTA()" @ 0x40d1e3d8
0x405a0278            [    ] VALUE: number 3
0x405a0270            [    ] VALUE: string "VOLTA" @ 0x416a4068
0x405a0268            [    ] VALUE: string "VOLTA(3)" @ 0x413b3f40
0x405a0260            [    ] VALUE: table @ 0x40178230 (asize: 0, hmask: 0x7)
0x405a0258            [    ] FRAME: [L] delta=2, Lua function @ 0x414f8708, 3 upvalues, "@/home/leon/Documents/git/home/dombrain-service/devices/energomeraDombrain.lua":29
0x405a0250            [    ] VALUE: table @ 0x40d309b0 (asize: 0, hmask: 0xf)
0x405a0248            [    ] FRAME: [L] delta=5, Lua function @ 0x40146cc8, 0 upvalues, "@/home/leon/Documents/git/home/dombrain-service/dombrainSensors.lua":113
0x405a0240            [    ] VALUE: number 60
0x405a0238            [    ] VALUE: number 1616420280
0x405a0230            [    ] VALUE: table @ 0x4058eab8 (asize: 0, hmask: 0x7)
0x405a0228            [    ] VALUE: table @ 0x40d309b0 (asize: 0, hmask: 0xf)
0x405a0220            [    ] FRAME: [CP] delta=1, Lua function @ 0x4058ea20, 3 upvalues, "@/home/leon/Documents/git/home/dombrain-service/dombrainSensors.lua":23
0x405a0218            [S   ] FRAME: dummy L

Из замеченных мной странностей. В приложенном выше трейсе, в буфере присутствует строка :22.7,\"Humidity\":38.0,\"DewPoint\":7.7, это ответ на запрос из другого модуля.
Возможно это не связано, но похоже на неочищенный буфер другого запроса.

11:55пожаловаться #3

ОБ

Олег Бабин in Tarantool

`lj-tab 0x4059f120`

11:57пожаловаться #4

(gdb) lj-tab 0x4059f120
Array part: 0 slots
Hash part: 2 nodes
0x4059ee08: { string "transfer-encoding" @ 0x40380610 } => { table @ 0x4059ee40 (asize: 3, hmask: 0x0) }; next = 0x0
0x4059ee20: { string "connection" @ 0x401183b8 } => { table @ 0x4059f148 (asize: 3, hmask: 0x0) }; next = 0x0
(gdb)

11:58пожаловаться #5

ОБ

Олег Бабин in Tarantool

Попробуйте с помощью lj-tab и lj-val поискать что-то подозрительное в этих хидерах

Т.е. пока что есть headers {"transfer-encoding" => 0x4059ee40; connection => 0x4059f148}

12:01пожаловаться #6

Всем доброе время суток.
Пишу приложение на в tarantool которое активно обращается к внешним http ресурсам, создается множество файберов.
Периодически стала появляться проблема: процесс tarantool грузит ядро на 100%, tarantoolctl enter не подключается. Вероятно где-то образовался бесконечный цикл...
Версия

Tarantool 2.6.2-0-g34d504d7d

В документации нашел подходящий раздел: "Просмотр состояния сервера".
Выполнил сбор показателей производительности: perf record -g -p.
Выполнил формирование читаемого отчета:

perf report -n -g --stdio

Но не понятно, какой файбер, какие инструкции съели процессор.

Из отчета вижу, что 99.9% процессора приходится сюда:

71.85%--http_parse_header_line
28.15%--luaT_httpc_request

К сожалению мне не понятно - куда копать дальше.
Подскажите следующие шаги для выяснения проблемной части кода

если можете полностью показать переменную (буфер), который попал в вызов http_parse_header_line, думаю этого будет достаточно для воспроизведения.

12:08пожаловаться #7

В lj-stack выше, на запрос к http://10.9.7.170:8080/energomera/?VOLTA() должен был прийти ответ:

[1.895,226.605,2.134]

В gdb не могу найти таблицу с реальным ответом. А реальный ответ, теоретически мог быть битым

12:14пожаловаться #8

Вот что-то похожее.

(gdb) lj-tab 0x4059f090
Array part: 0 slots
Hash part: 2 nodes
0x4059f0b8: { string "status" @ 0x413b5920 } => { number 408 }; next = 0x0
0x4059f0d0: { string "reason" @ 0x40118398 } => { string "Timeout was reached" @ 0x4059f0f0 }; next = 0x0

Получается, что не было ничего в теле ответа. Клиент не ответил

12:20пожаловаться #9

Вот что-то похожее.

(gdb) lj-tab 0x4059f090
Array part: 0 slots
Hash part: 2 nodes
0x4059f0b8: { string "status" @ 0x413b5920 } => { number 408 }; next = 0x0
0x4059f0d0: { string "reason" @ 0x40118398 } => { string "Timeout was reached" @ 0x4059f0f0 }; next = 0x0

Получается, что не было ничего в теле ответа. Клиент не ответил

а можете просто установить gdb на фрейм http_parse_header_line и сделать
p *bufp
(если я правильно помню как пользоваться gdb)

12:24пожаловаться #10

А ещё можно собрать при помощи тулзы корку (https://github.com/tarantool/tarantool/issues/5569) и прислать

12:26пожаловаться #11

(gdb) frame 0
#0  http_parse_header_line (prsr=prsr@entry=0x7f61a217fe60, bufp=bufp@entry=0x7f61a217fe58,
    end_buf=end_buf@entry=0x7f61a1778078 "e\":22.7,\"Humidity\":38.0,\"DewPoint\":7.7,\"Pressure\":992.3},\"MHZ19B\":{\"Model\":\"B\",\"CarbonDioxide\":400,\"Temperature\":25.0},\"PressureUnit\":\"hPa\",\"TempUnit\":\"C\"}}oad\r\nAccess-Control-Allow-Origin: *\r\nAccess-"..., max_hname_len=max_hname_len@entry=32) at ./src/lib/http_parser/http_parser.c:227
227             prsr->hdr_name_idx = 0;
(gdb) p *prsr
$25 = {
  hdr_value_start = 0x7f61a177806f "chunked\r\ne\":22.7,\"Humidity\":38.0,\"DewPoint\":7.7,\"Pressure\":992.3},\"MHZ19B\":{\"Model\":\"B\",\"CarbonDioxide\":400,\"Temperature\":25.0},\"PressureUnit\":\"hPa\",\"TempUnit\":\"C\"}}oad\r\nAccess-Control-Allow-Origin: *"..., hdr_value_end = 0x7f61a1778076 "\r\ne\":22.7,\"Humidity\":38.0,\"DewPoint\":7.7,\"Pressure\":992.3},\"MHZ19B\":{\"Model\":\"B\",\"CarbonDioxide\":400,\"Temperature\":25.0},\"PressureUnit\":\"hPa\",\"TempUnit\":\"C\"}}oad\r\nAccess-Control-Allow-Origin: *\r\nAcces"...,
  http_major = 1, http_minor = 1, hdr_name = 0x362b210 "transfer-encoding", hdr_name_idx = 0}
(gdb) p *bufp
$26 = 0x981974ccc074 <error: Cannot access memory at address 0x981974ccc074>
(gdb)

Я как обезьяна тыкаю в клавиши, слабо понимаю что делают :)

p *bufp

видимо не то выводит, в вот

p *prsr

что-то вывел, похожее на содержимое ответа на другой запрос (точно не на http://10.9.7.170:8080/energomera/?VOLTA()).

12:45пожаловаться #12

А ещё можно собрать при помощи тулзы корку (https://github.com/tarantool/tarantool/issues/5569) и прислать

Это попробую, но выложить сразу не смогу, канал узкий у меня. Ссылку вам в личку скинуть?

12:45пожаловаться #13

Это попробую, но выложить сразу не смогу, канал узкий у меня. Ссылку вам в личку скинуть?

Да, можно в личку

12:49пожаловаться #14

Michael Filonenko in Tarantool

p (char*)bufp

12:49пожаловаться #15

p (char*)bufp

там

int http_parse_header_line(struct http_parser *prsr, char **bufp, const char *end_buf, int max_hname_len)

12:55пожаловаться #16

p (char*)bufp

(gdb) frame 0
#0  http_parse_header_line (prsr=prsr@entry=0x7f61a217fe60, bufp=bufp@entry=0x7f61a217fe58, 
    end_buf=end_buf@entry=0x7f61a1778078 "e\":22.7,\"Humidity\":38.0,\"DewPoint\":7.7,\"Pressure\":992.3},\"MHZ19B\":{\"Model\":\"B\",\"CarbonDioxide\":400,\"Temperature\":25.0},\"PressureUnit\":\"hPa\",\"TempUnit\":\"C\"}}oad\r\nAccess-Control-Allow-Origin: *\r\nAccess-"..., max_hname_len=max_hname_len@entry=32) at ./src/lib/http_parser/http_parser.c:227
227             prsr->hdr_name_idx = 0;
(gdb) p (char*)bufp
$36 = 0x7f61a217fe58 "t\300\314t\031\230"
(gdb)

12:55пожаловаться #17

Michael Filonenko in Tarantool

там

int http_parse_header_line(struct http_parser *prsr, char **bufp, const char *end_buf, int max_hname_len)

понял

12:57пожаловаться #18

Alexandr in Tarantool

Привет, а 15.tarantool.org больше не работает?

13:55пожаловаться #19

Vladislav Grubov in Tarantool

живее всех живых