[lldb] Don't print script output twice in HandleCommand

[JDevlieghere]

Summary

When executing a script command in HandleCommand(s) we currently print its output twice: once directly to the debugger's output stream, and once as part of HandleCommand's result. You can see this issue in action when adding a breakpoint command:

(lldb) b main
Breakpoint 1: where = main.out`main + 13 at main.cpp:2:3, address = 0x0000000100003fad
(lldb) break command add 1 -o "script print(\"Hey!\")"
(lldb) r
Process 76041 launched: '/tmp/main.out' (x86_64)
Hey!
(lldb)  script print("Hey!")
Hey!

Process 76041 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
    frame #0: 0x0000000100003fad main.out`main at main.cpp:2:3

The issue is that HandleCommands uses a temporary CommandReturnObject. When running a one-liner with script, the script interpreter redirects the I/O from to the command object through ScriptInterpreterIORedirect which sets the immediate output on the temporary result and causes the result to be printed the first time. HandleCommand will then copy the result's output into its own result and print it a second time, not knowing that it has already been printed.

I'm not entirely sure why ScriptInterpreterIORedirect relies on an immediate output file, but there are several parts of LLDB that rely on it, so I'm hesitant to change that. We could check in HandleCommands if someone set immediate mode on our temporary result and not copy it into the final result when that's the case. A better solution in my opinion, which I implemented in this patch, is a "hermetic" mode for the CommandReturnObject which prevents anyone from setting and immediate stream on the temporary result by the command interpreter. This should prevent similar bugs if there are other places that try to do this.

I added a new test using the breakpoint command and fixed a Lua test that already suffered from this issue.

[jingham]

A command that knew it was streaming a lot of output is supposed to be able to choose to have the CommandInterpreter directly stream the results while the command is executing. That's good for something that is likely to print a lot of output, since then you don't have to wait for the command to be done to start seeing results. Of course, you still have to gather the command into the Return object as well since that's part of the CommandInterpreter contract. So you have to be careful not to print it twice. Maybe this code is part of the implementation of that?

[aprantl]

lldb/include/lldb/Interpreter/CommandReturnObject.h

167

bool m_hermetic = false;

lldb/source/Interpreter/CommandReturnObject.cpp

44

then we don't need this

157

or this

[JDevlieghere]

lldb/include/lldb/Interpreter/CommandReturnObject.h

167

This is the second time someone has suggested to use in-class member initializers. It's not what we've been doing in LLDB so far, but I am a fan of it personally, so I'm going to interpret this as what we want to do moving forward. I believe it's even a C++ core guideline. Maybe we can have a clang tidy check to enforce this.

lldb/source/Interpreter/CommandReturnObject.cpp

157

We would still need this :-)

[JDevlieghere]

Use in-class initializers

[jingham]

In D103349#2791614, @JDevlieghere wrote:

Use in-class initializers

I'm all for in-class initializers, but I think it is confusing to use them piecemeal, where some ivars in a class have initializers and some are initialized in the constructor's definition.

[shafik]

lldb/include/lldb/Interpreter/CommandReturnObject.h

167

This is idiomatic C++ and we should be using this feature going forward. It is more readable then a crowded mem-init-list and really makes a big difference when there are multiple constructors.

[JDevlieghere]

Don't try to be cute: s/Hermetic/SuppressImmediateOutput/

[jingham]

HandleCommands really does need to do this suppression, and this is a fine way to do it. I can't think of any other place where you would need to do this suppression after an admittedly non-exhaustive search. So LGTM.

[thakis]

lldb/lldb/test/Shell/Breakpoint/breakpoint-command.test

1

Did you mean to put this file in lldb/lldb/test/Shell/Breakpoint/breakpoint-command.test or should it be in lldb/test/Shell/Breakpoint/breakpoint-command.test (just one "lldb/")?

[JDevlieghere]

lldb/lldb/test/Shell/Breakpoint/breakpoint-command.test

1

Yeah, this seems like a patch prefix mistake on my end. I'll move the file. Thanks!

[JDevlieghere]

lldb/lldb/test/Shell/Breakpoint/breakpoint-command.test

1

a4aa705d52e818cf526f5e41cce8e719befd97a6

lldb/include/lldb/Interpreter/CommandReturnObject.h

Stream &GetErrorStream() {
     if (!stream_sp) {
       stream_sp = std::make_shared<StreamString>();
       m_err_stream.SetStreamAtIndex(eStreamStringIndex, stream_sp);
     }
     return m_err_stream;
   }
 
   void SetImmediateOutputFile(lldb::FileSP file_sp) {
+    if (m_suppress_immediate_output)
+      return;
     lldb::StreamSP stream_sp(new StreamFile(file_sp));
     m_out_stream.SetStreamAtIndex(eImmediateStreamIndex, stream_sp);
   }
 
   void SetImmediateErrorFile(lldb::FileSP file_sp) {
+    if (m_suppress_immediate_output)
+      return;
     lldb::StreamSP stream_sp(new StreamFile(file_sp));
     m_err_stream.SetStreamAtIndex(eImmediateStreamIndex, stream_sp);
   }
 
   void SetImmediateOutputStream(const lldb::StreamSP &stream_sp) {
+    if (m_suppress_immediate_output)
+      return;
     m_out_stream.SetStreamAtIndex(eImmediateStreamIndex, stream_sp);
   }
 
   void SetImmediateErrorStream(const lldb::StreamSP &stream_sp) {
+    if (m_suppress_immediate_output)
+      return;
     m_err_stream.SetStreamAtIndex(eImmediateStreamIndex, stream_sp);
   }
 
   lldb::StreamSP GetImmediateOutputStream() {
     return m_out_stream.GetStreamAtIndex(eImmediateStreamIndex);
   }
 
   lldb::StreamSP GetImmediateErrorStream() {
public:
   bool GetDidChangeProcessState();
 
   void SetDidChangeProcessState(bool b);
 
   bool GetInteractive() const;
 
   void SetInteractive(bool b);
 
+  bool GetSuppressImmediateOutput() const;
+
+  void SetSuppressImmediateOutput(bool b);
+
 private:
   enum { eStreamStringIndex = 0, eImmediateStreamIndex = 1 };
 
   StreamTee m_out_stream;
   StreamTee m_err_stream;
 
-  lldb::ReturnStatus m_status;
-  bool m_did_change_process_state;
-  bool m_interactive; // If true, then the input handle from the debugger will
-                      // be hooked up
+  lldb::ReturnStatus m_status = lldb::eReturnStatusStarted;
+
+  bool m_did_change_process_state = false;
+  bool m_suppress_immediate_output = false;
+
+  /// If true, then the input handle from the debugger will be hooked up.
+  bool m_interactive = true;
 };
 
 } // namespace lldb_private
 
 #endif // LLDB_INTERPRETER_COMMANDRETURNOBJECT_H

lldb/lldb/test/Shell/Breakpoint/breakpoint-command.test

+# RUN: %build %p/Inputs/dummy-target.c -o %t.out
+# RUN: %lldb %t.out -o 'b main' -o 'break command add 1 -o "script print(95000 + 126)"' -o 'r'
+
+# CHECK: 95125
+# CHECK-NOT: 95126

lldb/source/Interpreter/CommandInterpreter.cpp

for (size_t idx = 0; idx < num_lines && !WasInterrupted(); idx++) {
     if (options.GetEchoCommands()) {
       // TODO: Add Stream support.
       result.AppendMessageWithFormat("%s %s\n",
                                      m_debugger.GetPrompt().str().c_str(), cmd);
     }
 
     CommandReturnObject tmp_result(m_debugger.GetUseColor());
     tmp_result.SetInteractive(result.GetInteractive());
+    tmp_result.SetSuppressImmediateOutput(true);
 
     // We might call into a regex or alias command, in which case the
     // add_to_history will get lost.  This m_command_source_depth dingus is the
     // way we turn off adding to the history in that case, so set it up here.
     if (!options.GetAddToHistory())
       m_command_source_depth++;
     bool success = HandleCommand(cmd, options.m_add_to_history, tmp_result);
     if (!options.GetAddToHistory())

lldb/source/Interpreter/CommandReturnObject.cpp

if (!s.empty()) {
     const char last_char = *s.rbegin();
     add_newline = last_char != '\n' && last_char != '\r';
   }
   if (add_newline)
     strm.EOL();
 }
 
 CommandReturnObject::CommandReturnObject(bool colors)
-    : m_out_stream(colors), m_err_stream(colors),
-      m_status(eReturnStatusStarted), m_did_change_process_state(false),
-      m_interactive(true) {}
+    : m_out_stream(colors), m_err_stream(colors) {}
 
 void CommandReturnObject::AppendErrorWithFormat(const char *format, ...) {
   SetStatus(eReturnStatusFailed);
 
   if (!format)
     return;
   va_list args;
   va_start(args, format);
void CommandReturnObject::Clear() {
   stream_sp = m_out_stream.GetStreamAtIndex(eStreamStringIndex);
   if (stream_sp)
     static_cast<StreamString *>(stream_sp.get())->Clear();
   stream_sp = m_err_stream.GetStreamAtIndex(eStreamStringIndex);
   if (stream_sp)
     static_cast<StreamString *>(stream_sp.get())->Clear();
   m_status = eReturnStatusStarted;
   m_did_change_process_state = false;
+  m_suppress_immediate_output = false;
   m_interactive = true;
 }
 
 bool CommandReturnObject::GetDidChangeProcessState() {
   return m_did_change_process_state;
 }
 
 void CommandReturnObject::SetDidChangeProcessState(bool b) {
   m_did_change_process_state = b;
 }
 
 bool CommandReturnObject::GetInteractive() const { return m_interactive; }
 
 void CommandReturnObject::SetInteractive(bool b) { m_interactive = b; }
+
+bool CommandReturnObject::GetSuppressImmediateOutput() const {
+  return m_suppress_immediate_output;
+}
+
+void CommandReturnObject::SetSuppressImmediateOutput(bool b) {
+  m_suppress_immediate_output = b;
+}

lldb/test/Shell/Breakpoint/breakpoint-command.test

+# RUN: %build %p/Inputs/dummy-target.c -o %t.out
+# RUN: %lldb %t.out -o 'b main' -o 'break command add 1 -o "script print(95000 + 126)"' -o 'r'
+
+# CHECK: 95125
+# CHECK-NOT: 95126

lldb/test/Shell/ScriptInterpreter/Lua/nested_sessions.test

 # REQUIRES: lua
 # RUN: mkdir -p %t
 # RUN: echo "int main() { return 0; }" | %clang_host -x c - -o %t/foo
 # RUN: echo "int main() { return 0; }" | %clang_host -x c - -o %t/bar
 # RUN:  %lldb --script-language lua -o "file %t/bar" -o "file %t/foo" -s %S/Inputs/nested_sessions.in  -s %S/Inputs/nested_sessions_2.in 2>&1 | FileCheck %s
 # CHECK: script
 # CHECK-NEXT: foo foo
 # CHECK-NEXT: foo bar
 # CHECK-NEXT: foo bar
-# CHECK-NEXT: foo bar
 # CHECK: script
 # CHECK-NEXT: bar bar