[lldb-dev] Evaluating the same expression at the same breakpoint gets slower after a certain number of steps
Guilherme Andrade via lldb-dev
lldb-dev at lists.llvm.org
Thu Jul 11 09:53:56 PDT 2019
Speaking more generally, can evaluating an expression with no side effects
affect the outcome of subsequent evaluations? I.e, is it possible for the
expression evaluation X to produce different results in the following
scenarios?
Scenario 1: <set of instructions A> <expression evaluation with no side
effects> <set of instructions B> <expression evaluation X>
Scenario 2: <set of instructions A> <set of instructions B> <expression
evaluation X>
Thanks!
On Tue, Jul 9, 2019 at 2:52 PM Guilherme Andrade <guiandrade at google.com>
wrote:
> Thanks for looking into this, Jason. I ended up realizing that it isn't
> about the number of evaluations; it is the exact location of the
> breakpoints that matters.
>
> I'm being able to consistently reproduce this by having two breakpoints (A
> and B) inside the same function, but B being inside the scope of a for loop
> that defines a couple extra variables. The first evaluation of
> 'undefinedVariable' at breakpoint A generates the following
> FindExternalLexicalDecls calls:
>
> FindExternalLexicalDecls[5] on (ASTContext*)000001566104F030 in 'Type0'
> (CXXRecordDecl*)0000015668964438
> FindExternalLexicalDecls[6] on (ASTContext*)000001566104F030 in 'Type6'
> (CXXRecordDecl*)0000015668961BA8
> FindExternalLexicalDecls[7] on (ASTContext*)000001566104F030 in 'Type7'
> (CXXRecordDecl*)0000015668961A68
> FindExternalLexicalDecls[8] on (ASTContext*)000001566104F030 in 'Type8'
> (CXXRecordDecl*)0000015674F56208
> FindExternalLexicalDecls[9] on (ASTContext*)000001566104F030 in 'Type9'
> (ClassTemplateSpecializationDecl*)0000015674F56CD0
> FindExternalLexicalDecls[10] on (ASTContext*)000001566104F030 in 'Type10'
> (CXXRecordDecl*)0000015668964300
> FindExternalLexicalDecls[11] on (ASTContext*)000001566104F030 in 'Type10'
> (CXXRecordDecl*)0000015668964300
> FindExternalLexicalDecls[12] on (ASTContext*)000001566104F030 in 'Type0'
> (CXXRecordDecl*)0000015668964438
> FindExternalLexicalDecls[13] on (ASTContext*)000001566104F030 in 'Type11'
> (EnumDecl*)0000015674F62778
>
> Then, the evaluation at breakpoint B generates:
>
> FindExternalLexicalDecls[19] on (ASTContext*)000001F1F6275320 in 'Type0'
> (CXXRecordDecl*)000001F1EA798868
> FindExternalLexicalDecls[20] on (ASTContext*)000001F1F6275320 in 'Type1'
> (CXXRecordDecl*)000001F1EA799098
> FindExternalLexicalDecls[21] on (ASTContext*)000001F1F6275320 in 'Type2'
> (ClassTemplateSpecializationDecl*)000001F1EA7A0D50
> FindExternalLexicalDecls[22] on (ASTContext*)000001F1F6275320 in 'Type3'
> (CXXRecordDecl*)000001F1EA79D818
> FindExternalLexicalDecls[23] on (ASTContext*)000001F1F6275320 in 'Type4'
> (CXXRecordDecl*)000001F1EA79D548
> FindExternalLexicalDecls[24] on (ASTContext*)000001F1F6275320 in 'Type5'
> (CXXRecordDecl*)000001F1EA7A2A08
> FindExternalLexicalDecls[25] on (ASTContext*)000001F1F6275320 in 'Type6'
> (CXXRecordDecl*)000001F1EA7BB368
> FindExternalLexicalDecls[26] on (ASTContext*)000001F1F6275320 in 'Type7'
> (CXXRecordDecl*)000001F1EA7BB228
> FindExternalLexicalDecls[27] on (ASTContext*)000001F1F6275320 in 'Type8'
> (CXXRecordDecl*)000001F1F68B9088
> FindExternalLexicalDecls[28] on (ASTContext*)000001F1F6275320 in 'Type9'
> (ClassTemplateSpecializationDecl*)000001F1F68B2AC0
> FindExternalLexicalDecls[29] on (ASTContext*)000001F1F6275320 in 'Type10'
> (CXXRecordDecl*)000001F1EA798730
> FindExternalLexicalDecls[30] on (ASTContext*)000001F1F6275320 in 'Type10'
> (CXXRecordDecl*)000001F1EA798730
> FindExternalLexicalDecls[31] on (ASTContext*)000001F1F6275320 in 'Type0'
> (CXXRecordDecl*)000001F1EA798868
> FindExternalLexicalDecls[32] on (ASTContext*)000001F1F6275320 in 'Type11'
> (EnumDecl*)000001F1F68CB3E0
> FindExternalLexicalDecls[33] on (ASTContext*)000001F1F6275320 in 'Type12'
> (CXXRecordDecl*)000001F1E2351F48
>
> And the subsequent evaluations at breakpoint A, which are slower, produce:
>
> FindExternalLexicalDecls[91] on (ASTContext*)000001566104F030 in 'Type0'
> (CXXRecordDecl*)000001566895C3B8
> FindExternalLexicalDecls[92] on (ASTContext*)000001566104F030 in 'Type1'
> (CXXRecordDecl*)000001566895CBE8
> FindExternalLexicalDecls[93] on (ASTContext*)000001566104F030 in 'Type2'
> (ClassTemplateSpecializationDecl*)00000156689678D0
> FindExternalLexicalDecls[94] on (ASTContext*)000001566104F030 in 'Type3'
> (CXXRecordDecl*)0000015668964398
> FindExternalLexicalDecls[95] on (ASTContext*)000001566104F030 in 'Type4'
> (CXXRecordDecl*)00000156689640C8
> FindExternalLexicalDecls[96] on (ASTContext*)000001566104F030 in 'Type5'
> (CXXRecordDecl*)0000015674F608B8
> FindExternalLexicalDecls[97] on (ASTContext*)000001566104F030 in 'Type6'
> (CXXRecordDecl*)0000015674F731B8
> FindExternalLexicalDecls[98] on (ASTContext*)000001566104F030 in 'Type7'
> (CXXRecordDecl*)0000015674F73078
> FindExternalLexicalDecls[99] on (ASTContext*)000001566104F030 in 'Type8'
> (CXXRecordDecl*)0000015674F7B278
> FindExternalLexicalDecls[100] on (ASTContext*)000001566104F030 in 'Type9'
> (ClassTemplateSpecializationDecl*)0000015674F78CF0
> FindExternalLexicalDecls[101] on (ASTContext*)000001566104F030 in 'Type10'
> (CXXRecordDecl*)000001566895C280
> FindExternalLexicalDecls[102] on (ASTContext*)000001566104F030 in 'Type10'
> (CXXRecordDecl*)000001566895C280
> FindExternalLexicalDecls[103] on (ASTContext*)000001566104F030 in 'Type0'
> (CXXRecordDecl*)000001566895C3B8
> FindExternalLexicalDecls[104] on (ASTContext*)000001566104F030 in 'Type11'
> (EnumDecl*)0000015674F81510
>
> The FindExternalVisibleDecls entries remain the same among all evaluations
> at breakpoint A.
>
> So, Jim, if symbols are getting added at B or types are being completed,
> then the extra FindExternalLexicalDecls calls for Type1-5 is intended
> behavior?
>
> On Mon, Jul 8, 2019 at 7:04 PM Jim Ingham <jingham at apple.com> wrote:
>
>> Are any sources for symbols getting added to the process as you go along,
>> like new shared library loads? You are asking for a non-existent name, so
>> every new source of debug info is a new place to look.
>>
>> It's also possible that we are completing some types during the course of
>> the expression evaluation, and then the newly completed types become
>> themselves new places to look for this non-existent name.
>>
>> You can see what is getting looked up by turning in the expression log
>> (log enable lldb expr) then looking for the FindExternalVisibleDecls
>> entries.
>>
>> Jim
>>
>>
>> > On Jul 8, 2019, at 3:33 PM, Jason Molenda via lldb-dev <
>> lldb-dev at lists.llvm.org> wrote:
>> >
>> > Hm, that's interesting.
>> >
>> > I tried running a debug lldb on /bin/ls. then I attached from another
>> lldb. I put a breakpoint on CommandObjectTargetModulesLookup::DoExecute
>> and resumed execution. In the debuggee lldb, I did
>> >
>> > tar mod loo -a 0
>> >
>> >
>> > and auto-repeated return so the same command would be executed over and
>> over.
>> >
>> > In the debugger lldb, I tried adding a command to the breakpoint,
>> >
>> > br comm add
>> > p does_not_exist
>> > DONE
>> >
>> > and continuing - after a couple dozen times, I didn't see a slowdown.
>> I tried adding a breakpoint condition,
>> >
>> > br mod -c 'doesNotExist == 1' 1
>> >
>> > and continuing, and didn't see a slowdown after a few dozen repetitions.
>> >
>> > I'm on macOS using .o file DWARF debugging.
>> >
>> > I'm sure there's a bug here, but it may be more specific to the
>> platform and type of debug info that you're using? It could be that lldb is
>> too small of a project to repo this problem too.
>> >
>> >
>> >
>> >> On Jul 4, 2019, at 11:38 AM, Guilherme Andrade via lldb-dev <
>> lldb-dev at lists.llvm.org> wrote:
>> >>
>> >> I have two breakpoint inside methods that are called every frame (C++
>> project using Unreal), and every time one of them is reached, I evaluate
>> one expression (I'm being able to reproduce this using an undefined name,
>> say "undefinedVariable"). After a few iterations (usually tens), the time
>> it takes for LLDB to say that name doesn't exist increases, despite being
>> the same expression, at the same breakpoint and the call stack remaining
>> unchanged.
>> >>
>> >> I've noticed that the number of lexical Decl queries and imports
>> conducted by Clang reported in 'Local metrics' increase.
>> >>
>> >> They go from:
>> >> Number of visible Decl queries by name : 29
>> >> Number of lexical Decl queries : 9
>> >> Number of imports initiated by LLDB : 15
>> >> Number of imports conducted by Clang : 827
>> >> Number of Decls completed : 5
>> >> Number of records laid out : 2
>> >>
>> >> To:
>> >> Number of visible Decl queries by name : 29
>> >> Number of lexical Decl queries : 14
>> >> Number of imports initiated by LLDB : 15
>> >> Number of imports conducted by Clang : 1342
>> >> Number of Decls completed : 5
>> >> Number of records laid out : 2
>> >>
>> >> Also, the number of SymbolFileDWARF operations in the logs jumps from
>> 366 to 406.
>> >>
>> >> So, I've got two questions. 1) Is it safe to say that those extra
>> imports and Decl queries are responsible for the performance loss? 2) Why
>> do they happen?
>> >>
>> >> Thanks!
>> >> _______________________________________________
>> >> lldb-dev mailing list
>> >> lldb-dev at lists.llvm.org
>> >> https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-dev
>> >
>> > _______________________________________________
>> > lldb-dev mailing list
>> > lldb-dev at lists.llvm.org
>> > https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-dev
>>
>
--
Guilherme Andrade | Software Engineer | guiandrade at google.com | Google
Waterloo, Canada <https://careers.google.com/locations/waterloo/>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.llvm.org/pipermail/lldb-dev/attachments/20190711/8521e92e/attachment-0001.html>
More information about the lldb-dev
mailing list