From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtp-out1.suse.de (smtp-out1.suse.de [IPv6:2a07:de40:b251:101:10:150:64:1]) by sourceware.org (Postfix) with ESMTPS id 78DF1384DEC4 for ; Mon, 19 Feb 2024 08:23:55 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.2 sourceware.org 78DF1384DEC4 Authentication-Results: sourceware.org; dmarc=pass (p=none dis=none) header.from=suse.de Authentication-Results: sourceware.org; spf=pass smtp.mailfrom=suse.de ARC-Filter: OpenARC Filter v1.0.0 sourceware.org 78DF1384DEC4 Authentication-Results: server2.sourceware.org; arc=none smtp.remote-ip=2a07:de40:b251:101:10:150:64:1 ARC-Seal: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1708331042; cv=none; b=dKuNCxI5LNBXZTIUkhnhMGacd/KMN/OoHS5+3jDvLxE/0XWJX797B6McLW5iIR/fdlVdG3cGetbsdY+P++/Qg5V1Txwj53ncJndwmaKxNAwri34vURNf1zDYkoS0Omgdy1KcHgJwMeUZ3xcGhrWqEXGwc1ahhRyA5kwp7MPBfKI= ARC-Message-Signature: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1708331042; c=relaxed/simple; bh=3BhfuYApqdvisKK9pOye9Y5hTSTKmqhD5BA3oaShn2c=; h=DKIM-Signature:DKIM-Signature:DKIM-Signature:DKIM-Signature:From: To:Subject:Date:Message-Id:MIME-Version; b=ETu9RzdRqLUIEDBuVwwwE1W0fILeI0Ptvik0dmQ8MskYT/8p3FK8+oK0ni8y1927MuNIlVB97sVAq4cskW1ersLYwUGUN0W2GDwLSs24u3eMb87bIu3LyVkSfG9IOesCHPwT87oZGf+/YVc7WXEs8XXAZZBOoz3/zQWdsPBIeLk= ARC-Authentication-Results: i=1; server2.sourceware.org Received: from imap1.dmz-prg2.suse.org (imap1.dmz-prg2.suse.org [10.150.64.97]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by smtp-out1.suse.de (Postfix) with ESMTPS id 94375222ED for ; Mon, 19 Feb 2024 08:23:52 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.de; s=susede2_rsa; t=1708331034; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=UN6K5TOmYQGV50JNcthZhwMJgdIa9AVzLdgPLwlvjw8=; b=deUFQmhjogL6/bgu7Zvpb3b0PybnGgzJtBe/IFxHqgLn+UA7Ed044CVuxLCkxAk+5dTfvI 3fB4O6xWJ07iPwuH1YL6EDNPiQM/Y+TtliMcSv5SKMPrmgOiaNUY0JWPPafXCZel2wNvIq MyWke4u+eaifGoS0cZTAAH9dVXhIFB8= DKIM-Signature: v=1; a=ed25519-sha256; c=relaxed/relaxed; d=suse.de; s=susede2_ed25519; t=1708331034; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=UN6K5TOmYQGV50JNcthZhwMJgdIa9AVzLdgPLwlvjw8=; b=j/BijkSqW2q8EfE9CCs/9+bGO/TCilr2IQkeK1c7wwnapTRdF5iSC8dngv9ZWz4ePuDqCG A9Ezkq+9nGiTZbCw== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.de; s=susede2_rsa; t=1708331032; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=UN6K5TOmYQGV50JNcthZhwMJgdIa9AVzLdgPLwlvjw8=; b=kCbLaln6+Mxg12mTKu46d9aIe/nT4G5uwlZbY+A2y3we9PGazHWyTldwn0EZHJ+C36kHaL AZse4jSY+NCMS11r7srB3YpiSItPYtwOInWer9P8aEBjFJSVm8fCAaPrY34/FIhS08aas/ 0V2Iyc4j1N9ljIm6HBfNOHLgoz/HZSg= DKIM-Signature: v=1; a=ed25519-sha256; c=relaxed/relaxed; d=suse.de; s=susede2_ed25519; t=1708331032; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=UN6K5TOmYQGV50JNcthZhwMJgdIa9AVzLdgPLwlvjw8=; b=z6+eScmL5dQtF5qmt0ijWfAginmjXvqjMAh2vAolgUpJSTF1/T7B5yNrMUKLkzW60cupFu X3kKYjn/o41L9hBA== Received: from imap1.dmz-prg2.suse.org (localhost [127.0.0.1]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by imap1.dmz-prg2.suse.org (Postfix) with ESMTPS id 7BEDE13AAC for ; Mon, 19 Feb 2024 08:23:52 +0000 (UTC) Received: from dovecot-director2.suse.de ([2a07:de40:b281:106:10:150:64:167]) by imap1.dmz-prg2.suse.org with ESMTPSA id eCQZHRgQ02WaBAAAD6G6ig (envelope-from ) for ; Mon, 19 Feb 2024 08:23:52 +0000 From: Tom de Vries To: gdb-patches@sourceware.org Subject: [PATCH 5/8] [gdb/dap] Fix race between dap startup and dap log file Date: Mon, 19 Feb 2024 09:23:38 +0100 Message-Id: <20240219082341.21313-5-tdevries@suse.de> X-Mailer: git-send-email 2.35.3 In-Reply-To: <20240219082341.21313-1-tdevries@suse.de> References: <20240219082341.21313-1-tdevries@suse.de> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit Authentication-Results: smtp-out1.suse.de; none X-Spam-Level: X-Spam-Score: 0.70 X-Spamd-Result: default: False [0.70 / 50.00]; ARC_NA(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; FROM_HAS_DN(0.00)[]; R_MISSING_CHARSET(2.50)[]; TO_MATCH_ENVRCPT_ALL(0.00)[]; MIME_GOOD(-0.10)[text/plain]; PREVIOUSLY_DELIVERED(0.00)[gdb-patches@sourceware.org]; BROKEN_CONTENT_TYPE(1.50)[]; RCPT_COUNT_ONE(0.00)[1]; NEURAL_HAM_LONG(-1.00)[-1.000]; RCVD_COUNT_THREE(0.00)[3]; TO_DN_NONE(0.00)[]; DKIM_SIGNED(0.00)[suse.de:s=susede2_rsa,suse.de:s=susede2_ed25519]; NEURAL_HAM_SHORT(-0.20)[-1.000]; MID_CONTAINS_FROM(1.00)[]; DBL_BLOCKED_OPENRESOLVER(0.00)[sourceware.org:url]; FUZZY_BLOCKED(0.00)[rspamd.com]; FROM_EQ_ENVFROM(0.00)[]; MIME_TRACE(0.00)[0:+]; RCVD_TLS_ALL(0.00)[]; BAYES_HAM(-3.00)[100.00%] X-Spam-Status: No, score=-12.2 required=5.0 tests=BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,GIT_PATCH_0,SPF_HELO_NONE,SPF_PASS,TXREP,T_SCC_BODY_TEXT_LINE autolearn=ham autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on server2.sourceware.org List-Id: In dap_gdb_start we do: ... append GDBFLAGS " -iex \"set debug dap-log-file $logfile\" -q -i=dap" ... While the dap log file setting comes before the dap interpreter setting, the order is the other way around: - first, the dap interpreter is started - second, the -iex commands are executed and the log file is initialized. Consequently, there's a race between dap interpreter startup and dap log file initialization. This cannot be fixed by using -eiex instead. Before the interpreter is started, the "set debug dap-log-file" command is not yet registered. Fix this by: - initially logging to a string instead, and - dumping the string to the log file once the log file is initialized. This has the drawback that the string can keep growing indefinitely if a log file is never set, this will be addressed in a following commit. Tested on aarch64-linux. PR dap/31386 Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=31386 --- gdb/python/lib/gdb/dap/startup.py | 17 ++++++++++++++--- gdb/testsuite/gdb.dap/eof.exp | 3 +++ gdb/testsuite/lib/dap-support.exp | 10 ++++++++++ 3 files changed, 27 insertions(+), 3 deletions(-) diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py index fc86442db42..596012688ac 100644 --- a/gdb/python/lib/gdb/dap/startup.py +++ b/gdb/python/lib/gdb/dap/startup.py @@ -21,6 +21,7 @@ import queue import threading import traceback import sys +import io from enum import IntEnum, auto @@ -147,7 +148,7 @@ class LoggingParam(gdb.Parameter): lock = threading.Lock() with lock: - log_file = None + log_file = io.StringIO() def __init__(self): super().__init__( @@ -157,12 +158,20 @@ class LoggingParam(gdb.Parameter): def get_set_string(self): with dap_log.lock: + initial_log = None + if isinstance(self.log_file, io.StringIO): + initial_log = self.log_file.getvalue() + self.log_file.close() + self.log_file = None # Close any existing log file, no matter what. if self.log_file is not None: self.log_file.close() self.log_file = None if self.value is not None: self.log_file = open(self.value, "w") + if initial_log != None: + print(initial_log, file=self.log_file) + self.log_file.flush() return "" @@ -174,7 +183,8 @@ def log(something, level=LogLevel.DEFAULT): with dap_log.lock: if dap_log.log_file is not None and level <= _log_level.value: print(something, file=dap_log.log_file) - dap_log.log_file.flush() + if not isinstance(dap_log.log_file, io.StringIO): + dap_log.log_file.flush() def thread_log(something, level=LogLevel.DEFAULT): @@ -190,7 +200,8 @@ def log_stack(level=LogLevel.DEFAULT): with dap_log.lock: if dap_log.log_file is not None and level <= _log_level.value: traceback.print_exc(file=dap_log.log_file) - dap_log.log_file.flush() + if not isinstance(dap_log.log_file, io.StringIO): + dap_log.log_file.flush() @in_gdb_thread diff --git a/gdb/testsuite/gdb.dap/eof.exp b/gdb/testsuite/gdb.dap/eof.exp index 9c17725c0d0..404a069246f 100644 --- a/gdb/testsuite/gdb.dap/eof.exp +++ b/gdb/testsuite/gdb.dap/eof.exp @@ -35,3 +35,6 @@ catch "wait -i $gdb_spawn_id" unset gdb_spawn_id dap_check_log_file + +# Check that first log message is present. +dap_check_log_file_re [string_to_regexp "+++ set python print-stack full"] diff --git a/gdb/testsuite/lib/dap-support.exp b/gdb/testsuite/lib/dap-support.exp index 31f036eddf2..5818d815df3 100644 --- a/gdb/testsuite/lib/dap-support.exp +++ b/gdb/testsuite/lib/dap-support.exp @@ -366,6 +366,16 @@ proc dap_check_log_file {} { } } +# Read the most recent DAP log file and check that regexp RE matches. +proc dap_check_log_file_re { re } { + set fd [open [current_dap_log_file]] + set contents [read $fd] + close $fd + + set ok [regexp $re $contents] + gdb_assert {$ok} "log file matched $re" +} + # Cleanly shut down gdb. TERMINATE is passed as the terminateDebuggee # parameter to the request. proc dap_shutdown {{terminate false}} { -- 2.35.3