From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from [87.239.111.99] (localhost [127.0.0.1]) by dev.tarantool.org (Postfix) with ESMTP id C58FE6EC55; Wed, 28 Jul 2021 16:44:15 +0300 (MSK) DKIM-Filter: OpenDKIM Filter v2.11.0 dev.tarantool.org C58FE6EC55 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=tarantool.org; s=dev; t=1627479855; bh=Ow3Hi0+Og79ER/gPv+CbjdRdZloNOgs1Qp8nW3N1+KQ=; h=To:Date:In-Reply-To:References:Subject:List-Id:List-Unsubscribe: List-Archive:List-Post:List-Help:List-Subscribe:From:Reply-To: From; b=MNxVJDAuOnGdhWwTIn5DCjPCeQL63wwa+e0sf0AQgqDXYNSSNNlqzjb3V1jx+ry+U yncsw7MHvuFaOtc9Vp3FiK8yNDW7lJtlfxCF+7nXWmtVkdbGcd+xWVC8kim3OGkBf9 Uw0GdcZX4XeNbCN7hURmei9k7IrRJxe4PlwnK3VQ= Received: from smtp47.i.mail.ru (smtp47.i.mail.ru [94.100.177.107]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dev.tarantool.org (Postfix) with ESMTPS id 8F2FE6EC5C for ; Wed, 28 Jul 2021 16:43:21 +0300 (MSK) DKIM-Filter: OpenDKIM Filter v2.11.0 dev.tarantool.org 8F2FE6EC5C Received: by smtp47.i.mail.ru with esmtpa (envelope-from ) id 1m8jqB-0003Ga-AE; Wed, 28 Jul 2021 16:43:20 +0300 To: tarantool-patches@dev.tarantool.org, imun@tarantool.org, skaplun@tarantool.org Date: Wed, 28 Jul 2021 20:42:59 +0700 Message-Id: <20210728134259.1113235-3-m.shishatskiy@tarantool.org> X-Mailer: git-send-email 2.32.0 In-Reply-To: <20210728134259.1113235-1-m.shishatskiy@tarantool.org> References: <20210728134259.1113235-1-m.shishatskiy@tarantool.org> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-7564579A: 646B95376F6C166E X-77F55803: 4F1203BC0FB41BD941C43E597735A9C366EE405EC28A2001F8302D8429E0DE58182A05F538085040608DDFD4E9BF5FD867F869A2B3894F2F62D9D486E46B39730B71A31F8CC4626F X-7FA49CB5: FF5795518A3D127A4AD6D5ED66289B5278DA827A17800CE7AEF9C2E372EE2CB3EA1F7E6F0F101C67BD4B6F7A4D31EC0BCC500DACC3FED6E28638F802B75D45FF8AA50765F7900637A1EC320DD04F715B8638F802B75D45FF36EB9D2243A4F8B5A6FCA7DBDB1FC311F39EFFDF887939037866D6147AF826D88738FCCF9F9031489DC6B184CD178247117882F4460429724CE54428C33FAD305F5C1EE8F4F765FC2EE5AD8F952D28FBA471835C12D1D9774AD6D5ED66289B52BA9C0B312567BB23117882F446042972877693876707352033AC447995A7AD182CC0D3CB04F14752D2E47CDBA5A96583BA9C0B312567BB2376E601842F6C81A19E625A9149C048EE140C956E756FBB7A1C9461EB66F04EBFD8FC6C240DEA7642DBF02ECDB25306B2B78CF848AE20165D0A6AB1C7CE11FEE324D079F6B4507B16C0837EA9F3D19764C4224003CC836476EA7A3FFF5B025636E2021AF6380DFAD1A18204E546F3947CB11811A4A51E3B096D1867E19FE1407959CC434672EE6371089D37D7C0E48F6C8AA50765F7900637BBEA499411984DA1EFF80C71ABB335746BA297DBC24807EABDAD6C7F3747799A X-B7AD71C0: AC4F5C86D027EB782CDD5689AFBDA7A213B5FB47DCBC3458834459D11680B505D69DAB4247E33C3674629456D86F9AF4 X-C1DE0DAB: C20DE7B7AB408E4181F030C43753B8186998911F362727C414F749A5E30D975C7BEA09003D200E087C962CC016EE1AD68ADF62E3BBC3922F9C2B6934AE262D3EE7EAB7254005DCED7532B743992DF240BDC6A1CF3F042BAD6DF99611D93F60EF795D7D556640A06E699F904B3F4130E343918A1A30D5E7FCCB5012B2E24CD356 X-C8649E89: 4E36BF7865823D7055A7F0CF078B5EC49A30900B95165D34E9B0C12ABED551379DB6A9A33C090537E5A803EA1441D9DFF2139D40CFA7F92597314172A87EB2361D7E09C32AA3244CC7EBF05E781FF563ED53BFB1753F6377F522A1CF68F4BE05927AC6DF5659F194 X-D57D3AED: 3ZO7eAau8CL7WIMRKs4sN3D3tLDjz0dLbV79QFUyzQ2Ujvy7cMT6pYYqY16iZVKkSc3dCLJ7zSJH7+u4VD18S7Vl4ZUrpaVfd2+vE6kuoey4m4VkSEu530nj6fImhcD4MUrOEAnl0W826KZ9Q+tr5ycPtXkTV4k65bRjmOUUP8cvGozZ33TWg5HZplvhhXbhDGzqmQDTd6OAevLeAnq3Ra9uf7zvY2zzsIhlcp/Y7m53TZgf2aB4JOg4gkr2biojiF1u9eOpfTQSGb8ODVVfGA== X-Mailru-Sender: 2317F5BEA8D613097CB8A225516EF027BE1BAC68D3663C055127E54EB6917B5ECF04E3B6581E3306FF6B26DEAE20951894E739346DD9ABB838AE394B99C5394F99323991B04ED3930F27244EEAA5B9A5AE208404248635DF X-Mras: Ok Subject: [Tarantool-patches] [PATCH luajit v2 2/2] memprof: extend symtab with info about traces X-BeenThere: tarantool-patches@dev.tarantool.org X-Mailman-Version: 2.1.34 Precedence: list List-Id: Tarantool development patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , From: Mikhail Shishatskiy via Tarantool-patches Reply-To: Mikhail Shishatskiy Errors-To: tarantool-patches-bounces@dev.tarantool.org Sender: "Tarantool-patches" This patch extends the memprof symtab by adding information about traces, which are present at the start of profiling. The symtab format changed with adding entry, which consists of a trace number, address of function proto, and line, where trace recording started. Also, the memprof parser was adjusted to recognize new symtab entries and associate them with allocation events from traces. This patch also provides tests to test the behavior of the memory profiler with JIT turned on. Part of tarantool/tarantool#5814 --- Issue: https://github.com/tarantool/tarantool/issues/5814 Branch: https://github.com/tarantool/luajit/tree/shishqa/gh-5814-group-allocations-on-trace-by-trace-number CI: https://github.com/tarantool/tarantool/tree/shishqa/gh-5814-group-allocations-on-trace-by-trace-number src/lj_memprof.c | 19 +++ src/lj_memprof.h | 7 +- .../misclib-memprof-lapi.test.lua | 121 +++++++++++++----- tools/utils/symtab.lua | 41 +++++- 4 files changed, 150 insertions(+), 38 deletions(-) diff --git a/src/lj_memprof.c b/src/lj_memprof.c index 0c7e9e89..87512c3a 100644 --- a/src/lj_memprof.c +++ b/src/lj_memprof.c @@ -18,6 +18,7 @@ #include "lj_obj.h" #include "lj_frame.h" #include "lj_debug.h" +#include "lj_trace.h" /* --------------------------------- Symtab --------------------------------- */ @@ -43,6 +44,24 @@ static void dump_symtab(struct lj_wbuf *out, const struct global_State *g) lj_wbuf_addu64(out, (uint64_t)pt->firstline); break; } + case (~LJ_TTRACE): { + GCtrace *trace = gco2trace(o); + GCproto *pt = &gcref(trace->startpt)->pt; + + const BCIns *startpc = mref(trace->startpc, const BCIns); + lua_assert(startpc >= proto_bc(pt) && + startpc < proto_bc(pt) + pt->sizebc); + + BCLine lineno = lj_debug_line(pt, proto_bcpos(pt, startpc)); + lua_assert(lineno >= 0); + + lj_wbuf_addbyte(out, SYMTAB_TRACE); + lj_wbuf_addu64(out, (uint64_t)trace->traceno); + lj_wbuf_addu64(out, (uintptr_t)pt); + lj_wbuf_addu64(out, (uint64_t)lineno); + + break; + } default: break; } diff --git a/src/lj_memprof.h b/src/lj_memprof.h index e3f55433..9e950b94 100644 --- a/src/lj_memprof.h +++ b/src/lj_memprof.h @@ -16,7 +16,7 @@ #include "lj_def.h" #include "lj_wbuf.h" -#define LJS_CURRENT_VERSION 0x1 +#define LJS_CURRENT_VERSION 0x2 /* ** symtab format: @@ -25,13 +25,15 @@ ** prologue := 'l' 'j' 's' version reserved ** version := ** reserved := -** sym := sym-lua | sym-final +** sym := sym-lua | sym-trace | sym-final ** sym-lua := sym-header sym-addr sym-chunk sym-line +** sym-trace := sym-header trace-no sym-addr sym-line ** sym-header := ** sym-addr := ** sym-chunk := string ** sym-line := ** sym-final := sym-header +** trace-no := ** string := string-len string-payload ** string-len := ** string-payload := {string-len} @@ -51,6 +53,7 @@ */ #define SYMTAB_LFUNC ((uint8_t)0) +#define SYMTAB_TRACE ((uint8_t)1) #define SYMTAB_FINAL ((uint8_t)0x80) #define LJM_CURRENT_FORMAT_VERSION 0x02 diff --git a/test/tarantool-tests/misclib-memprof-lapi.test.lua b/test/tarantool-tests/misclib-memprof-lapi.test.lua index 06d96b3b..b7e456e1 100644 --- a/test/tarantool-tests/misclib-memprof-lapi.test.lua +++ b/test/tarantool-tests/misclib-memprof-lapi.test.lua @@ -1,13 +1,18 @@ +local utils = require "utils" + -- Memprof is implemented for x86 and x64 architectures only. -require("utils").skipcond( +utils.skipcond( jit.arch ~= "x86" and jit.arch ~= "x64", jit.arch.." architecture is NIY for memprof" ) +-- Disabled on *BSD due to #4819. +utils.skipcond(jit.os == 'BSD', 'Disabled due to #4819') + local tap = require("tap") local test = tap.test("misc-memprof-lapi") -test:plan(13) +test:plan(16) jit.off() jit.flush() @@ -22,7 +27,7 @@ local symtab = require "utils.symtab" local TMP_BINFILE = arg[0]:gsub(".+/([^/]+)%.test%.lua$", "%.%1.memprofdata.tmp.bin") local BAD_PATH = arg[0]:gsub(".+/([^/]+)%.test%.lua$", "%1/memprofdata.tmp.bin") -local function payload() +local function default_payload() -- Preallocate table to avoid table array part reallocations. local _ = table_new(100, 0) @@ -37,7 +42,7 @@ local function payload() collectgarbage() end -local function generate_output(filename) +local function generate_output(filename, payload) -- Clean up all garbage to avoid pollution of free. collectgarbage() @@ -52,19 +57,48 @@ local function generate_output(filename) assert(res, err) end +local function generate_parsed_output(payload) + local res, err = pcall(generate_output, TMP_BINFILE, payload) + + -- Want to cleanup carefully if something went wrong. + if not res then + os.remove(TMP_BINFILE) + error(err) + end + + local reader = bufread.new(TMP_BINFILE) + local symbols = symtab.parse(reader) + local events = memprof.parse(reader) + + -- We don't need it any more. + os.remove(TMP_BINFILE) + + return symbols, events +end + local function fill_ev_type(events, symbols, event_type) local ev_type = {} for _, event in pairs(events[event_type]) do local addr = event.loc.addr - if addr == 0 then + local traceno = event.loc.traceno + if traceno ~= 0 then + local trace_loc = symbols.trace[traceno] + addr = trace_loc.addr + ev_type[trace_loc.line] = { + name = string.format("TRACE [%d] %s:%d", + traceno, symbols.lfunc[addr].source, symbols.lfunc[addr].linedefined + ), + num = event.num, + } + elseif addr == 0 then ev_type.INTERNAL = { name = "INTERNAL", num = event.num, } - elseif symbols[addr] then + elseif symbols.lfunc[addr] then ev_type[event.loc.line] = { name = string.format( - "%s:%d", symbols[addr].source, symbols[addr].linedefined + "%s:%d", symbols.lfunc[addr].source, symbols.lfunc[addr].linedefined ), num = event.num, } @@ -77,12 +111,36 @@ local function form_source_line(line) return string.format("@%s:%d", arg[0], line) end -local function check_alloc_report(alloc, line, function_line, nevents) - assert(form_source_line(function_line) == alloc[line].name) - assert(alloc[line].num == nevents, ("got=%d, expected=%d"):format( - alloc[line].num, +local function nevents_eq(event, nevents) + assert(event.num == nevents, ("got=%d, expected=%d"):format( + event.num, + nevents + )) +end + +local function nevents_gr(event, nevents) + assert(event.num > nevents, ("got=%d, expected>%d"):format( + event.num, nevents )) +end + +local function check_alloc_report(alloc, traceno, line, function_line, + nevents, cmp_events) + assert(alloc[line], ("no event on line %d"):format(line)) + local event = alloc[line] + local expected_name + if traceno ~= 0 then + expected_name = string.format("TRACE [%d] ", traceno).. + form_source_line(function_line) + else + expected_name = form_source_line(function_line) + end + assert(expected_name == event.name, ("got='%s', expected='%s'"):format( + event.name, + expected_name + )) + cmp_events(event, nevents) return true end @@ -107,20 +165,7 @@ test:ok(res == nil and err:match("profiler is not running")) test:ok(type(errno) == "number") -- Test profiler output and parse. -res, err = pcall(generate_output, TMP_BINFILE) - --- Want to cleanup carefully if something went wrong. -if not res then - os.remove(TMP_BINFILE) - error(err) -end - -local reader = bufread.new(TMP_BINFILE) -local symbols = symtab.parse(reader) -local events = memprof.parse(reader, symbols) - --- We don't need it any more. -os.remove(TMP_BINFILE) +local symbols, events = generate_parsed_output(default_payload) local alloc = fill_ev_type(events, symbols, "alloc") local free = fill_ev_type(events, symbols, "free") @@ -131,9 +176,9 @@ local free = fill_ev_type(events, symbols, "free") -- the number of allocations. -- 1 event - alocation of table by itself + 1 allocation -- of array part as far it is bigger than LJ_MAX_COLOSIZE (16). -test:ok(check_alloc_report(alloc, 27, 25, 2)) +test:ok(check_alloc_report(alloc, 0, 32, 30, 2, nevents_eq)) -- 100 strings allocations. -test:ok(check_alloc_report(alloc, 32, 25, 100)) +test:ok(check_alloc_report(alloc, 0, 37, 30, 100, nevents_eq)) -- Collect all previous allocated objects. test:ok(free.INTERNAL.num == 102) @@ -141,8 +186,8 @@ test:ok(free.INTERNAL.num == 102) -- Tests for leak-only option. -- See also https://github.com/tarantool/tarantool/issues/5812. local heap_delta = process.form_heap_delta(events, symbols) -local tab_alloc_stats = heap_delta[form_source_line(27)] -local str_alloc_stats = heap_delta[form_source_line(32)] +local tab_alloc_stats = heap_delta[form_source_line(32)] +local str_alloc_stats = heap_delta[form_source_line(37)] test:ok(tab_alloc_stats.nalloc == tab_alloc_stats.nfree) test:ok(tab_alloc_stats.dbytes == 0) test:ok(str_alloc_stats.nalloc == str_alloc_stats.nfree) @@ -166,5 +211,23 @@ local co = coroutine.create(f) coroutine.resume(co) misc.memprof.stop() +-- Test profiler with enabled JIT. jit.on() + +-- Pregenerate traces to get expected output: +default_payload() + +symbols, events = generate_parsed_output(default_payload) + +alloc = fill_ev_type(events, symbols, "alloc") + +-- We expect, that loop will be compiled into a trace. +-- Depends on system, there will be 99 or 100 allocations +-- from trace, so expect greater than 98. +test:ok(check_alloc_report(alloc, 1, 35, 30, 98, nevents_gr)) +-- See same checks with jit.off(). +test:ok(check_alloc_report(alloc, 0, 32, 30, 2, nevents_eq)) +-- Collect all previous allocated objects. +test:ok(free.INTERNAL.num == 102) + os.exit(test:check() and 0 or 1) diff --git a/tools/utils/symtab.lua b/tools/utils/symtab.lua index 3ed1dd13..8151ecf8 100644 --- a/tools/utils/symtab.lua +++ b/tools/utils/symtab.lua @@ -10,11 +10,12 @@ local band = bit.band local string_format = string.format local LJS_MAGIC = "ljs" -local LJS_CURRENT_VERSION = 1 +local LJS_CURRENT_VERSION = 0x2 local LJS_EPILOGUE_HEADER = 0x80 local LJS_SYMTYPE_MASK = 0x03 local SYMTAB_LFUNC = 0 +local SYMTAB_TRACE = 1 local M = {} @@ -24,18 +25,33 @@ local function parse_sym_lfunc(reader, symtab) local sym_chunk = reader:read_string() local sym_line = reader:read_uleb128() - symtab[sym_addr] = { + symtab.lfunc[sym_addr] = { source = sym_chunk, linedefined = sym_line, } end +local function parse_sym_trace(reader, symtab) + local traceno = reader:read_uleb128() + local sym_addr = reader:read_uleb128() + local sym_line = reader:read_uleb128() + + symtab.trace[traceno] = { + addr = sym_addr, + line = sym_line, + } +end + local parsers = { [SYMTAB_LFUNC] = parse_sym_lfunc, + [SYMTAB_TRACE] = parse_sym_trace, } function M.parse(reader) - local symtab = {} + local symtab = { + lfunc = {}, + trace = {}, + } local magic = reader:read_octets(3) local version = reader:read_octets(1) @@ -73,18 +89,29 @@ function M.parse(reader) return symtab end -function M.demangle(symtab, loc) +local function demangle_lfunc(symtab, loc) local addr = loc.addr if addr == 0 then return "INTERNAL" + elseif symtab.lfunc[addr] then + return string_format("%s:%d", symtab.lfunc[addr].source, loc.line) end + return string_format("CFUNC %#x", addr) +end - if symtab[addr] then - return string_format("%s:%d", symtab[addr].source, loc.line) +function M.demangle(symtab, loc) + local traceno = loc.traceno + + if traceno ~= 0 then + if symtab.trace[traceno] then + local sym = demangle_lfunc(symtab, symtab.trace[traceno]) + return string_format("TRACE [%d] ", traceno)..sym + end + return string_format("TRACE [%d]", traceno) end - return string_format("CFUNC %#x", addr) + return demangle_lfunc(symtab, loc) end return M -- 2.32.0