From patchwork Thu May 5 06:55:13 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Alexandre Oliva X-Patchwork-Id: 1626699 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Authentication-Results: bilbo.ozlabs.org; dkim=pass (1024-bit key; unprotected) header.d=gcc.gnu.org header.i=@gcc.gnu.org header.a=rsa-sha256 header.s=default header.b=asDlrt3D; dkim-atps=neutral Authentication-Results: ozlabs.org; spf=pass (sender SPF authorized) smtp.mailfrom=gcc.gnu.org (client-ip=8.43.85.97; helo=sourceware.org; envelope-from=gcc-patches-bounces+incoming=patchwork.ozlabs.org@gcc.gnu.org; receiver=) Received: from sourceware.org (server2.sourceware.org [8.43.85.97]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by bilbo.ozlabs.org (Postfix) with ESMTPS id 4Kv4Gp4Kxtz9sBF for ; Thu, 5 May 2022 16:56:02 +1000 (AEST) Received: from server2.sourceware.org (localhost [IPv6:::1]) by sourceware.org (Postfix) with ESMTP id BD7B63856DCF for ; Thu, 5 May 2022 06:55:58 +0000 (GMT) DKIM-Filter: OpenDKIM Filter v2.11.0 sourceware.org BD7B63856DCF DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gcc.gnu.org; s=default; t=1651733758; bh=sO8lo8vtP5uSu4+jSXUm/2BBwxR/GDOjjtzpn8AMgLc=; h=To:Subject:Date:List-Id:List-Unsubscribe:List-Archive:List-Post: List-Help:List-Subscribe:From:Reply-To:From; b=asDlrt3Da8pq2e/vaiLxh45VPJG/Uwd8im5ShuHzJ2j+oOSI8Ts7+EjSB3duxqOxx GHvo5K2Y9GTK2uzllbmV0M5g6nUwwOo8LmVaJXPnPyl8zD6kfu/Vf4nt8yJ1TFDEaO jVMo1YrblsABaG7TP9SqAtcdfJwPBA0WiMkah5Os= X-Original-To: gcc-patches@gcc.gnu.org Delivered-To: gcc-patches@gcc.gnu.org Received: from rock.gnat.com (rock.gnat.com [IPv6:2620:20:4000:0:a9e:1ff:fe9b:1d1]) by sourceware.org (Postfix) with ESMTPS id E078C3857349; Thu, 5 May 2022 06:55:29 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.1 sourceware.org E078C3857349 Received: from localhost (localhost.localdomain [127.0.0.1]) by filtered-rock.gnat.com (Postfix) with ESMTP id A95261166E5; Thu, 5 May 2022 02:55:22 -0400 (EDT) X-Virus-Scanned: Debian amavisd-new at gnat.com Received: from rock.gnat.com ([127.0.0.1]) by localhost (rock.gnat.com [127.0.0.1]) (amavisd-new, port 10024) with LMTP id h2+1U0U4e01p; Thu, 5 May 2022 02:55:22 -0400 (EDT) Received: from free.home (tron.gnat.com [IPv6:2620:20:4000:0:46a8:42ff:fe0e:e294]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by rock.gnat.com (Postfix) with ESMTPS id 44AAE1166E4; Thu, 5 May 2022 02:55:22 -0400 (EDT) Received: from livre (livre.home [172.31.160.2]) by free.home (8.15.2/8.15.2) with ESMTPS id 2456tDdl2738237 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT); Thu, 5 May 2022 03:55:14 -0300 To: gcc-patches@gcc.gnu.org, libstdc++@gcc.gnu.org Subject: [PATCH] libstdc++: testsuite: async.cc early timeout Organization: Free thinker, does not speak for AdaCore Date: Thu, 05 May 2022 03:55:13 -0300 Message-ID: User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/25.2 (gnu/linux) MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.84 X-Spam-Status: No, score=-12.3 required=5.0 tests=BAYES_00, GIT_PATCH_0, KAM_DMARC_STATUS, KAM_SHORT, SPF_HELO_NONE, SPF_PASS, TXREP, T_SCC_BODY_TEXT_LINE autolearn=ham autolearn_force=no version=3.4.4 X-Spam-Checker-Version: SpamAssassin 3.4.4 (2020-01-24) on server2.sourceware.org X-BeenThere: gcc-patches@gcc.gnu.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Gcc-patches mailing list List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-Patchwork-Original-From: Alexandre Oliva via Gcc-patches From: Alexandre Oliva Reply-To: Alexandre Oliva Errors-To: gcc-patches-bounces+incoming=patchwork.ozlabs.org@gcc.gnu.org Sender: "Gcc-patches" The async call and future variable initialization may take a while to complete on uniprocessors, especially if the async call and other unrelated processes run before context switches back to the main thread. Taking steady_begin only then sometimes causes the 11*100ms in the slow clock, counted from before the async call, to not be enough for the measured wait to last 1s in the steady clock. I've seen it fall short of 1s by as little as a third of a tenth of a second in some cases, but in one surprisingly extreme case the elapsed wait time got only up to 216.7ms. Initializing both timestamps next to each other, before the async call, appears to avoid the problem entirely. I've renamed the variable moved out of the block so as to avoid name hiding in the subsequent block, that has another steady_begin variable. The second wait fails a lot less frequently, but the 2s limit has been exceeded, so I'm bumping up the max sleep to ~4s, and the tolerance to 3s. I wasn't sure about whether to leave the added outputs that I put in to confirm the failure modes. Please let me know in case they're undersirable, and I'll take them out. Regstrapped on x86_64-linux-gnu, ppc64le-linux-gnu, and also tested on ppc- and ppc64-vx7r2. Ok to install? for libstdc++-v3/ChangeLog * testsuite/30_threads/async/async.cc (test04): Initialize steady_start, renamed from steady_begin, next to slow_start. Increase tolerance for final wait. --- libstdc++-v3/testsuite/30_threads/async/async.cc | 17 ++++++++++++----- 1 file changed, 12 insertions(+), 5 deletions(-) diff --git a/libstdc++-v3/testsuite/30_threads/async/async.cc b/libstdc++-v3/testsuite/30_threads/async/async.cc index 38943ff1a9a5e..a36e1aee8bdef 100644 --- a/libstdc++-v3/testsuite/30_threads/async/async.cc +++ b/libstdc++-v3/testsuite/30_threads/async/async.cc @@ -20,6 +20,7 @@ // with this library; see the file COPYING3. If not see // . +#include #include #include @@ -133,6 +134,7 @@ void test04() { using namespace std::chrono; + auto const steady_start = steady_clock::now(); auto const slow_start = slow_clock::now(); future f1 = async(launch::async, []() { std::this_thread::sleep_for(std::chrono::seconds(2)); @@ -140,21 +142,26 @@ void test04() // Wait for ~1s { - auto const steady_begin = steady_clock::now(); auto const status = f1.wait_until(slow_start + milliseconds(100)); VERIFY(status == std::future_status::timeout); - auto const elapsed = steady_clock::now() - steady_begin; + auto const elapsed = steady_clock::now() - steady_start; + if (elapsed < seconds(1)) + std::cout << elapsed.count () << "ns < 1s" << std::endl; VERIFY(elapsed >= seconds(1)); VERIFY(elapsed < seconds(2)); } - // Wait for up to ~2s more + // Wait for up to ~4s more, but since the async sleep completes, the + // actual wait may be shorter than 1s. Tolerate 3s because 2s + // hasn't been enough in some extreme cases. { auto const steady_begin = steady_clock::now(); - auto const status = f1.wait_until(slow_start + milliseconds(300)); + auto const status = f1.wait_until(slow_start + milliseconds(500)); VERIFY(status == std::future_status::ready); auto const elapsed = steady_clock::now() - steady_begin; - VERIFY(elapsed < seconds(2)); + if (elapsed >= seconds(3)) + std::cout << elapsed.count () << "ns > 2s" << std::endl; + VERIFY(elapsed < seconds(3)); } }