From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.129.124]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.lore.kernel.org (Postfix) with ESMTPS id 3E9FEC433EF for ; Thu, 7 Jul 2022 04:07:58 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1657166877; h=from:from:sender:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:mime-version:mime-version: content-type:content-type: content-transfer-encoding:content-transfer-encoding:list-id:list-help: list-unsubscribe:list-subscribe:list-post; bh=9gWKvWOQqQyzhY3XqyMcNhXCMOl3FsRfvi9qCY2mosQ=; b=Cchup5iCfd+TkcbndCN4iuaCUr2HYThgWrjeVmZUxaBSjRUFVcW9lr+PR8AoJXOt3Pa6+Y 6WmyuF8RNKJHS1AuQJzkgIz45GzeTCvO3gBkUAW6TsiybC8QOeF8fOmhSUKCQfUMlVEEIt yIzBII+SNJx/5A3lzi0Lnek7ZhisunU= Received: from mimecast-mx02.redhat.com (mx3-rdu2.redhat.com [66.187.233.73]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-645-oIUe6AYaP3-StCPyXh7EEA-1; Thu, 07 Jul 2022 00:07:54 -0400 X-MC-Unique: oIUe6AYaP3-StCPyXh7EEA-1 Received: from smtp.corp.redhat.com (int-mx02.intmail.prod.int.rdu2.redhat.com [10.11.54.2]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id 911523C0CD3C; Thu, 7 Jul 2022 04:07:52 +0000 (UTC) Received: from mm-prod-listman-01.mail-001.prod.us-east-1.aws.redhat.com (unknown [10.30.29.100]) by smtp.corp.redhat.com (Postfix) with ESMTP id 2A88940EC004; Thu, 7 Jul 2022 04:07:51 +0000 (UTC) Received: from mm-prod-listman-01.mail-001.prod.us-east-1.aws.redhat.com (localhost [IPv6:::1]) by mm-prod-listman-01.mail-001.prod.us-east-1.aws.redhat.com (Postfix) with ESMTP id DC4D21947067; Thu, 7 Jul 2022 04:07:50 +0000 (UTC) Received: from smtp.corp.redhat.com (int-mx09.intmail.prod.int.rdu2.redhat.com [10.11.54.9]) by mm-prod-listman-01.mail-001.prod.us-east-1.aws.redhat.com (Postfix) with ESMTP id 2698A1947058 for ; Thu, 7 Jul 2022 04:07:49 +0000 (UTC) Received: by smtp.corp.redhat.com (Postfix) id 056A3492CA2; Thu, 7 Jul 2022 04:07:49 +0000 (UTC) Received: from mimecast-mx02.redhat.com (mimecast02.extmail.prod.ext.rdu2.redhat.com [10.11.55.18]) by smtp.corp.redhat.com (Postfix) with ESMTPS id 01323492C3B for ; Thu, 7 Jul 2022 04:07:48 +0000 (UTC) Received: from us-smtp-1.mimecast.com (us-smtp-delivery-1.mimecast.com [207.211.31.120]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id DDC26802D1F for ; Thu, 7 Jul 2022 04:07:48 +0000 (UTC) Received: from pb-smtp1.pobox.com (pb-smtp1.pobox.com [64.147.108.70]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-627-P5hXsnE2P2KH-_c4LghVgw-1; Thu, 07 Jul 2022 00:07:45 -0400 X-MC-Unique: P5hXsnE2P2KH-_c4LghVgw-1 Received: from pb-smtp1.pobox.com (unknown [127.0.0.1]) by pb-smtp1.pobox.com (Postfix) with ESMTP id E84B2138818 for ; Thu, 7 Jul 2022 00:05:29 -0400 (EDT) (envelope-from kenh@pobox.com) Received: from pb-smtp1.nyi.icgroup.com (unknown [127.0.0.1]) by pb-smtp1.pobox.com (Postfix) with ESMTP id DFABD138817 for ; Thu, 7 Jul 2022 00:05:29 -0400 (EDT) (envelope-from kenh@pobox.com) Received: from pietro.internal (unknown [72.66.57.248]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by pb-smtp1.pobox.com (Postfix) with ESMTPSA id 12124138816 for ; Thu, 7 Jul 2022 00:05:29 -0400 (EDT) (envelope-from kenh@pobox.com) From: Ken Hornstein To: linux-audit@redhat.com Subject: Trying to understand audisp-remote network behavior X-Face: "Evs"_GpJ]],xS)b$T2#V&{KfP_i2`TlPrY$Iv9+TQ!6+`~+l)#7I)0xr1>4hfd{#0B4 WIn3jU;bql;{2Uq%zw5bF4?%F&&j8@KaT?#vBGk}u07<+6/`.F-3_GA@6Bq5gN9\+s;_d gD\SW #]iN_U0 KUmOR.P<|um5yPkEpSD@*e` MIME-Version: 1.0 Date: Thu, 07 Jul 2022 00:05:28 -0400 X-Pobox-Relay-ID: 09B88252-FDAA-11EC-B0CC-5E84C8D8090B-90216062!pb-smtp1.pobox.com Message-Id: <20220707040529.DFABD138817@pb-smtp1.pobox.com> X-Mimecast-Impersonation-Protect: Policy=CLT - Impersonation Protection Definition; Similar Internal Domain=false; Similar Monitored External Domain=false; Custom External Domain=false; Mimecast External Domain=false; Newly Observed Domain=false; Internal User Name=false; Custom Display Name List=false; Reply-to Address Mismatch=false; Targeted Threat Dictionary=false; Mimecast Threat Dictionary=false; Custom Threat Dictionary=false X-Scanned-By: MIMEDefang 2.85 on 10.11.54.9 X-BeenThere: linux-audit@redhat.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: Linux Audit Discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: linux-audit-bounces@redhat.com Sender: "Linux-audit" X-Scanned-By: MIMEDefang 2.84 on 10.11.54.2 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=linux-audit-bounces@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit So we've been struggling with getting audisp-remote working in a reliable manner. In summary, it works but the networking seems fragile. We are using Kerberos authentication with audisp-remote, but that doesn't seem to be related to the fragility (sadly the Kerberos support does make it trivial to completely hang the server, but that's another issue). This is on RHEL 7 which ships with audit-2.8.5, but as far as I can tell the relevant code hasn't changed much from there to what is on GitHub. After staring at the code a lot and doing some experiments, here's what I believe to be true. I'll gladly take corrections for anything I get wrong. - If a connection has _never_ been made successfully by audisp-remote, it will retry the connection (in theory there's a limit to retries, but that seems to be per-message; it will retry on every new message). Fine, that seems reasonable. - If the connection is lost for almost any reason (see below), the connection is never retried using the default configuration. There might be some corner cases where a retry can happen, but in my experience that is rare. Once it's gone, it never gets retried, and audit messages build up until the queue overflows. - In theory if a graceful shutdown is received by audisp-remote (either a zero-length read or a "ENDING" audit message), then retries can happen; this is indicated by the "remote_ended" flag in the code. But in my experience that is rare; during my experiments when I rebooted our audit server that message was never sent (I guess the audit server stop was received after the interfaces were shut down). If the audit server crashes or you have a network failure, you end up getting an error on a write and then the network is marked down and you get into never-retry state. - If you turn on heartbeats via heartbeat_timeout, the network connection _will_ retry when a heartbeat is sent. However, the subtle issue here is that a heartbeat is only sent when there are no incoming audit messages within the heartbeat timeout. The key issue seems to be in this part of the loop in main() (this section is entered when audisp-remote receives an audit record): // See if input fd is also set if (FD_ISSET(ifd, &rfd)) { do { if (remote_fgets(event, sizeof(event), ifd)) { if (!transport_ok && remote_ended && (config.remote_ending_action == FA_RECONNECT || !connected_once)) { quiet = 1; if (init_transport() == ET_SUCCESS) { remote_ended = 0; connected_once = 1; } quiet = 0; } In short, when a new audit record is received, init_transport() (which tries to connect to the audit server) is only called _IF_ the connection is down (transport_ok == 0) _and_ remote_ended is true _and_ remote_ending_action is set to FA_RECONNECT (the default) _or_ there hasn't been at least one successful connection (connected_once == 0). The problem with that is at least in our environment remote_ended is never set to 1, so when the connection drops it is never retried, and there aren't any other entry points in the normal event loop that would ever cause the connection to retry. The heartbeat code calls relay_event() directly (code that sends audit events normally calls send_one() which returns if transport_ok is false) and relay_event() calls either relay_sock_ascii() or relay_sock_managed() and those two functions will call init_transport() if the network connection is down. But as mentioned above, you need to make sure that you try to send a heartbeat every so often; if you have a server generating audit messages constantly then there won't be a heartbeat if you set the heartbeat timeout too high. You _can_ get a network connection retry if you encounter an error inside of relay_sock_ascii() or relay_sock_managed(); I can't say that didn't happen with us, but it sure seemed like it wasn't sufficient and having the transport marked as failed was inevitible. So, I guess my questions are: - Is this all accurate? - Is this how it's SUPPOSED to be? At least for us, network glitches happen enough that most of our hosts ended up with overflowing audisp-remote queues. Setting the heartbeat timeout seems to have resolved that (but it took a little experimentation to figure out the right value). It just seems surprising that it was easy to get into a situation where you'd never retry a connection. --Ken -- Linux-audit mailing list Linux-audit@redhat.com https://listman.redhat.com/mailman/listinfo/linux-audit