From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 15758 invoked by alias); 6 Mar 2018 01:44:09 -0000 Mailing-List: contact gdb-patches-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Archive: List-Post: List-Help: , Sender: gdb-patches-owner@sourceware.org Received: (qmail 14204 invoked by uid 89); 6 Mar 2018 01:44:08 -0000 Authentication-Results: sourceware.org; auth=none X-Virus-Found: No X-Spam-SWARE-Status: No, score=-24.6 required=5.0 tests=AWL,BAYES_00,GIT_PATCH_0,GIT_PATCH_1,GIT_PATCH_2,GIT_PATCH_3,KAM_LAZY_DOMAIN_SECURITY,KAM_SHORT,T_RP_MATCHES_RCVD autolearn=ham version=3.3.2 spammy=7738, handmade, blurb X-HELO: mx1.redhat.com Received: from mx3-rdu2.redhat.com (HELO mx1.redhat.com) (66.187.233.73) by sourceware.org (qpsmtpd/0.93/v0.84-503-g423c35a) with ESMTP; Tue, 06 Mar 2018 01:44:05 +0000 Received: from smtp.corp.redhat.com (int-mx06.intmail.prod.int.rdu2.redhat.com [10.11.54.6]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 44C0C402277A for ; Tue, 6 Mar 2018 01:44:04 +0000 (UTC) Received: from localhost (unused-10-15-17-196.yyz.redhat.com [10.15.17.196]) by smtp.corp.redhat.com (Postfix) with ESMTP id C31F02144B20; Tue, 6 Mar 2018 01:44:03 +0000 (UTC) From: Sergio Durigan Junior To: Pedro Alves Cc: GDB Patches , Jan Kratochvil Subject: Re: [PATCH v2] Enable 'set print inferior-events' and cleanup attach/detach messages References: <20180124194714.26222-1-sergiodj@redhat.com> <20180131165735.4339-1-sergiodj@redhat.com> <79c5d1bc-d3de-494d-d559-9d4c848ebc0c@redhat.com> Date: Tue, 06 Mar 2018 01:44:00 -0000 In-Reply-To: <79c5d1bc-d3de-494d-d559-9d4c848ebc0c@redhat.com> (Pedro Alves's message of "Thu, 1 Feb 2018 17:17:37 +0000") Message-ID: <87k1uqx9jw.fsf@redhat.com> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/25.3 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain X-IsSubscribed: yes X-SW-Source: 2018-03/txt/msg00129.txt.bz2 On Thursday, February 01 2018, Pedro Alves wrote: > On 01/31/2018 04:57 PM, Sergio Durigan Junior wrote: >> This is a followup of Pedro's suggestion to turn 'set print >> inferior-events' always on, and do some cleanup on the messages >> printed by GDB when attaching/detaching a inferior, or when it exits. >> >> To make sure that the patch is correct, I've tested it with a handful >> of combinations of 'set follow-fork-mode', 'set detach-on-fork' and >> 'set print inferior-events'. In the end, I decided to make my >> hand-made test into an official testcase. More on that below. >> >> I've also made a few modifications to messages that are printed when >> 'set print inferior-events' is on. For example, a few of the messages >> did not contain the '[' and ']' as prefix/suffix, which led to a few >> inconsistencies like: >> >> Attaching after process 22995 fork to child process 22995. >> [New inferior 22999] >> Detaching after fork from child process 22999. >> [Inferior 22995 detached] >> [Inferior 2 (process 22999) exited normally] >> >> So I took the opportunity and included the square brackets where >> applicable. >> >> As suggested by Pedro, the "[Inferior %d exited]" message from >> 'exit_inferior' has been removed, because it got duplicated when >> 'inferior-events' is on. I'm also using the >> 'add_{thread,inferior}_silent' versions (instead of their verbose >> counterparts) on some locations, also to avoid duplicated messages. > > Can you give examples of the latter? (what led to 'add_{thread,inferior}_silent') [ Resurrecting the thread... ] Yes. Using add_thread, set print inferior-events on, set follow-fork-mode child, and set detach-on-fork on, I see: (gdb) run Starting program: a.out [Attaching after process 25088 fork to child process 25088.] [New inferior 25092] <--- duplicated [Detaching after fork from child process 25092.] [Inferior 25088 detached] [New process 25092] <--- duplicated [Inferior 2 (process 25092) exited normally] But using add_thread_silent (with the same configuration as before): (gdb) run Starting program: a.out [Attaching after process 26807 fork to child process 26807.] [New inferior 26811] [Detaching after fork from child process 26811.] [Inferior 26807 detached] [Inferior 2 (process 26811) exited normally] So we get rid of one duplicated line, produced by add_thread. As for the add_inferior_silent case (on inferiors.c:initialize_inferiors), it's useful to get rid of the: [New inferior 0] message that happens when initializing GDB. >> As for the tests, the configuration options being exercised are: >> >> - follow-fork-mode: child/parent >> - detach-on-fork: on/off >> - print inferior-events: on/off >> >> Built and regtested on BuildBot, without regressions. > > Can you update the log to include examples of what the new > output looks like? Both "set inferior-events on/off". > That makes it much easier to review/discuss/evaluate. Yes, that's a good idea. Sorry for not doing that earlier. > Can you say what happens to the output with > "set print inferior-events off" compared to current master? > Does output change in that case compared to today? Not changing > output is not the goal, but it'd be good to be clear. Based on a test using an inferior that just forks: #include int main () { fork (); return 0; } And with set follow-fork-mode child, current master does: (gdb) r Starting program: a.out [New process 5702] [Inferior 2 (process 5702) exited normally] And my patch does: (gdb) r Starting program: a.out [Inferior 2 (process 5993) exited normally] So yeah, we end up losing the notification of "[New process %d]" there, which comes from thread.c:add_thread_with_info. Pedantically, the "[Inferior 2 ... exited normally]" message should also be considered an inferior event, and maybe should not be printed. > I'm experimenting a bit, and I'm seeing some inconsistencies > that I wonder whether we should consider revising. > > For example, with "set print inferior-events on/off", we see, > for detach: > > (gdb) detach > Detaching from program: /home/pedro/gdb/build/gdb/testsuite/outputs/gdb.base/foll-fork/foll-fork, process 2685 > [Inferior 2685 detached] > (gdb) > > But for kill, we see: > > (gdb) k > Kill the program being debugged? (y or n) y > (gdb) > > Should detach vs kill be consistent? I'd think so off hand. Hm, alright. I can modify kill_command and print the message. WDYT: (gdb) kill Kill the program being debugged? (y or n) y [Inferior 14161 has been killed] ? > Another thing is related to what I was proposing in the other > thread. With the patch, we say: > > (gdb) c > Continuing. > [New inferior 3239] > [Inferior 5 (process 3236) exited normally] > > The "New inferior 3239" one is showing the target process ID, > which is confusing. I think we should tweak to mention the > inferior ID, like: > > (gdb) c > Continuing. > [New inferior 5 (process 3236)] > [Inferior 5 (process 3236) exited normally] This looks a bit redundant to me, but I think it's the best way (at least I couldn't think of a better one). Consider it done. > Looking at follow-fork child, detach-on-fork on, we see: > > [Attaching after process 12069 fork to child process 12069.] > [New inferior 12073] > [Detaching after fork from child process 12073.] > [Inferior 12069 detached] > [Inferior 2 (process 12073) exited normally] > > That could use some normalization to make messages consistent > with one another. > > [Attaching after process 12069 fork to child process 12069.] > [New inferior 2 (process 12073)] > [Detaching after fork from child process 12073.] > [Inferior 1 (process 12069) detached] > [Inferior 2 (process 12073) exited normally] > > (see more about this case below) > >> >> target_terminal::ours_for_output (); >> fprintf_filtered (gdb_stdlog, >> - _("Detaching after %s from child %s.\n"), >> + _("[Detaching after %s from child %s.]\n"), >> has_vforked ? "vfork" : "fork", >> target_pid_to_str (process_ptid)); > > I also noticed that this ends up with a period at the end, while > other [] notices don't, like (playing with "set detach-on-fork on"): > > [Detaching after fork from child process 3417.] > [Inferior 5 (process 3416) exited normally] Good point, I'll remove the periods. > >> diff --git a/gdb/testsuite/gdb.base/fork-detach-info.exp b/gdb/testsuite/gdb.base/fork-detach-info.exp >> new file mode 100644 >> index 0000000000..aa9a85c0d5 >> --- /dev/null >> +++ b/gdb/testsuite/gdb.base/fork-detach-info.exp > > Maybe this could use a different name, since this isn't > just about _detach_ info? > > fork-print-inferior-events.exp, maybe. Renamed. >> @@ -0,0 +1,68 @@ >> +# This testcase is part of GDB, the GNU debugger. >> + >> +# Copyright 2007-2018 Free Software Foundation, Inc. >> + >> +# This program is free software; you can redistribute it and/or modify >> +# it under the terms of the GNU General Public License as published by >> +# the Free Software Foundation; either version 3 of the License, or >> +# (at your option) any later version. >> +# >> +# This program is distributed in the hope that it will be useful, >> +# but WITHOUT ANY WARRANTY; without even the implied warranty of >> +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the >> +# GNU General Public License for more details. >> +# >> +# You should have received a copy of the GNU General Public License >> +# along with this program. If not, see . >> + > > Please add an intro comment mentioning what the testcase is about. Done. >> +if { [use_gdb_stub] || [target_info gdb_protocol] == "extended-remote" } { >> + untested "not supported on gdbserver" >> + return >> +} > > I see that this relies on "run", so can't work with use_gdb_stub. > But why is this not supported with extended-remote gdbserver? Just because, for extended-remote, the messages are a bit different: [Attaching after Thread 7738.7738 fork to child Thread 7738.7738] [New inferior 2 (process 7739)] [Detaching after fork from parent process 7738] [Inferior 7738 detached] [Inferior 2 (process 7739) exited normally] This case is easy, it would just require an adjustment to the first line (instead of "process $decimal" we'd expect "Thread $decimal\.$decimal"). There are more annoying cases, like: Reading /lib64/ld-linux-x86-64.so.2 from remote target... Reading /lib64/ld-2.26.so.debug from remote target... Reading /lib64/.debug/ld-2.26.so.debug from remote target... Reading /lib64/libm.so.6 from remote target... Reading /lib64/libc.so.6 from remote target... Reading /lib64/libm-2.26.so.debug from remote target... Reading /lib64/.debug/libm-2.26.so.debug from remote target... Reading /lib64/libc-2.26.so.debug from remote target... Reading /lib64/.debug/libc-2.26.so.debug from remote target... [Attaching after Thread 7762.7762 fork to child Thread 7762.7762] [New inferior 2 (process 7763)] Reading /lib64/libm.so.6 from remote target... Reading /lib64/libc.so.6 from remote target... Reading /lib64/ld-linux-x86-64.so.2 from remote target... Reading /lib64/libm-2.26.so.debug from remote target... Reading /lib64/.debug/libm-2.26.so.debug from remote target... Reading /lib64/libc-2.26.so.debug from remote target... Reading /lib64/.debug/libc-2.26.so.debug from remote target... Reading /lib64/ld-2.26.so.debug from remote target... Reading /lib64/.debug/ld-2.26.so.debug from remote target... Reading /lib64/ld-linux-x86-64.so.2 from remote target... [Inferior 2 (process 7763) exited normally] In this case, we'd have all the "Reading ..." messages to ignore, which makes it hard to match the consecutive lines we expect. Therefore, I thought it made sense to make this test local. Maybe a better solution for this would be to provide a similar test under gdb.server. Or just tweak the regexps. >> + >> +standard_testfile >> + >> +if { [prepare_for_testing "failed to prepare" $testfile $srcfile debug] } { >> + return -1 >> +} >> + >> +# This is the expected output for each of the test combinations >> +# below. The order here is important: >> +# >> +# follow-fork: child; detach-on-fork: on; inferior-events: on >> +# follow-fork: child; detach-on-fork: on; inferior-events: off >> +# follow-fork: child; detach-on-fork: off; inferior-events: on >> +# follow-fork: child; detach-on-fork: off; inferior-events: off >> +# follow-fork: parent; detach-on-fork: on; inferior-events: on >> +# follow-fork: parent; detach-on-fork: on; inferior-events: off >> +# follow-fork: parent; detach-on-fork: off; inferior-events: on >> +# follow-fork: parent; detach-on-fork: off; inferior-events: off >> +set expected_output [list \ >> + "\\\[Attaching after process $decimal fork to child process >> $decimal\\.\\\]\r\n\\\[New inferior $decimal\\\]\r\n\\\[Detaching >> after fork from child process $decimal\\.\\\]\r\n\\\[Inferior >> $decimal detached\\\]\r\n\\\[Inferior $decimal \\(process >> $decimal\\) exited normally\\\]" \ >> + "\\\[Inferior $decimal \\(process $decimal\\) exited normally\\\]" \ >> + "\\\[Attaching after process $decimal fork to child process $decimal\\.\\\]\r\n\\\[New inferior $decimal\\\]\r\n\\\[Inferior $decimal \\(process $decimal\\) exited normally\\\]" \ >> + "\\\[Inferior $decimal \\(process $decimal\\) exited normally\\\]" \ >> + "\\\[Detaching after fork from child process $decimal\\.\\\]\r\n\\\[Inferior $decimal \\(process $decimal\\) exited normally\\\]" \ >> + "\\\[Inferior $decimal \\(process $decimal\\) exited normally\\\]" \ >> + "\\\[New inferior $decimal\\\]\r\n\\\[Inferior $decimal \\(process $decimal\\) exited normally\\\]" \ >> + "\\\[Inferior $decimal \\(process $decimal\\) exited normally\\\]"] >> + > > I had a lot of trouble making sense of this big blurb of expected output. > I didn't know exactly what to suggest, so I played with it locally, and > I think putting the individual messages in variables helps a lot. > And then, I noticed that all the cases end up with > > \\\[Inferior $decimal \\(process $decimal\\) exited normally\\\] > > so we can factor it out. > > And then, if we iterate over print_inferior_events first, then > it's super clear that the "set print-inferior-events off" > case is always "no output". See attached patch on top of yours. Thanks for the patch, I applied it on top of what I have here. > The infrun.c hunk is there in my patch because while playing with > this, I noticed that gdb says that it's detaching the child > (and uses the child's pid), when in fact it is detaching the > parent! > > I.e., currently, "set follow-fork child", "set detach-on-fork on": > > [Attaching after process 12069 fork to child process 12069.] > [New inferior 2 12073] > [Detaching after fork from child process 12073.] <<< nope, it's detaching 12069 / the parent > [Inferior 12069 detached] <<< see? > [Inferior 2 (process 12073) exited normally] > > after that fix: > > [Attaching after process 18500 fork to child process 18500.] > [New inferior 18504] > [Detaching after fork from parent process 18500.] > [Inferior 18500 detached] > [Inferior 2 (process 18504) exited normally] Ah, good catch. ISTR having a strange feeling when examining these outputs, but couldn't tell why. I'll send a new version soon. Thanks, -- Sergio GPG key ID: 237A 54B1 0287 28BF 00EF 31F4 D0EB 7628 65FC 5E36 Please send encrypted e-mail if possible http://sergiodj.net/