From owner-freebsd-pf@FreeBSD.ORG Tue Mar 4 10:11:00 2008 Return-Path: Delivered-To: freebsd-pf@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 62BE91065674 for ; Tue, 4 Mar 2008 10:11:00 +0000 (UTC) (envelope-from silver.salonen@gmail.com) Received: from ug-out-1314.google.com (ug-out-1314.google.com [66.249.92.169]) by mx1.freebsd.org (Postfix) with ESMTP id EA1658FC2C for ; Tue, 4 Mar 2008 10:10:59 +0000 (UTC) (envelope-from silver.salonen@gmail.com) Received: by ug-out-1314.google.com with SMTP id y2so2668652uge.37 for ; Tue, 04 Mar 2008 02:10:58 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:from:to:subject:date:user-agent:references:in-reply-to:mime-version:content-type:content-transfer-encoding:content-disposition:message-id; bh=4mNOIlSmrObp2fDtt1oPGnf1L1ILwT9TUMUiQn1M6MY=; b=ihKFQh3zvIDflcSDehkBJ/woF7y76X9fRAyp1x0R4+agXaPzi/b6mYbW4McL962Pwcm31J3OJ2oOO6T8XsKheV6Kp6XifCmRW2JN0T1S7S4zNXmySi4EnBzNwJCpjfAIYpdEOVirR+G4fpivJZPKc9yXUY8BxcphldBpBR7TCOg= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=from:to:subject:date:user-agent:references:in-reply-to:mime-version:content-type:content-transfer-encoding:content-disposition:message-id; b=GiJR+TCtrmjV1pm6p/e/ErQpT9694TYeKekEC5N1cu02kVkL/TiDRfXR5jVykbcOc+Z83vmfcSfy4cL+dkHGYundjEEsz+HFGkKSk7UVtpBnhCV7NeUr0rI5acMG2w24ADoiGdevmU5anT7zB3qIabPvRb15V2FGhMEPzcqwdSM= Received: by 10.78.107.8 with SMTP id f8mr2106699huc.40.1204623827727; Tue, 04 Mar 2008 01:43:47 -0800 (PST) Received: from ?192.168.8.99? ( [195.50.198.178]) by mx.google.com with ESMTPS id i5sm3788769mue.7.2008.03.04.01.43.44 (version=TLSv1/SSLv3 cipher=OTHER); Tue, 04 Mar 2008 01:43:45 -0800 (PST) From: Silver Salonen To: freebsd-pf@freebsd.org Date: Tue, 4 Mar 2008 11:43:37 +0200 User-Agent: KMail/1.9.9 References: <200712180934.58755.silver.salonen@gmail.com> In-Reply-To: <200712180934.58755.silver.salonen@gmail.com> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline Message-Id: <200803041143.37873.silver.salonen@gmail.com> Subject: Re: occasional "Operation not permitted" on state-mismatch X-BeenThere: freebsd-pf@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: "Technical discussion and general questions about packet filter \(pf\)" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 04 Mar 2008 10:11:00 -0000 On Tuesday 18 December 2007 09:34, Silver Salonen wrote: > Sometimes I get just some connection timeout: CRITICAL - Socket timeout after > 2 seconds (I don't know what could cause that). > > I can see this behaviour in about every FreeBSD/PF machine I have. Hello. I'm still sitting on this error. It hasn't been so urgent as it's working quite OK, so I've been busy with other things. On testing the connection with Nagios plugin check_tcp to port 22, I've got the timeouts every minute or so - actually it's quite random and depends on traffic activity. The tcpdump shows that a packet leaves one side but never reaches the other. This one seems not to be related to the state-mismatch issue, as the counter doesn't increase or anything. I set pfctl debugging do 'loud', but I see nothing appearing in log at the time I get timeout. Some observations - connection from port 57733 is successful, but connection from port 57734 times out. * tcpdump on external interface SRC: ===== 11:21:07.358157 IP src-bsd.57733 > dst-bsd.ssh: S 57016355:57016355(0) win 65535 11:21:07.380850 IP dst-bsd.ssh > src-bsd.57733: S 3006112695:3006112695(0) ack 57016356 win 65535 11:21:07.381137 IP src-bsd.57733 > dst-bsd.ssh: . ack 1 win 33304 11:21:07.381302 IP src-bsd.57733 > dst-bsd.ssh: F 1:1(0) ack 1 win 33304 11:21:07.401295 IP dst-bsd.ssh > src-bsd.57733: . ack 2 win 33304 11:21:07.414093 IP dst-bsd.ssh > src-bsd.57733: P 1:40(39) ack 2 win 33304 11:21:07.414320 IP src-bsd.57733 > dst-bsd.ssh: R 57016357:57016357(0) win 0 11:21:07.414333 IP dst-bsd.ssh > src-bsd.57733: F 40:40(0) ack 2 win 33304 11:21:07.414373 IP src-bsd.57733 > dst-bsd.ssh: R 57016357:57016357(0) win 0 11:21:08.445833 IP src-bsd.57734 > dst-bsd.ssh: S 3894885836:3894885836(0) win 65535 ===== DST: ===== 11:21:07.354764 IP src-bsd.57733 > dst-bsd.ssh: S 57016355:57016355(0) win 65535 11:21:07.354849 IP dst-bsd.ssh > src-bsd.57733: S 3006112695:3006112695(0) ack 57016356 win 65535 11:21:07.368066 IP src-bsd.57733 > dst-bsd.ssh: . ack 1 win 33304 11:21:07.374921 IP src-bsd.57733 > dst-bsd.ssh: F 1:1(0) ack 1 win 33304 11:21:07.375032 IP dst-bsd.ssh > src-bsd.57733: . ack 2 win 33304 11:21:07.387897 IP dst-bsd.ssh > src-bsd.57733: P 1:40(39) ack 2 win 33304 11:21:07.388215 IP dst-bsd.ssh > src-bsd.57733: F 40:40(0) ack 2 win 33304 11:21:07.440012 IP src-bsd.57733 > dst-bsd.ssh: R 57016357:57016357(0) win 0 11:21:07.440187 IP src-bsd.57733 > dst-bsd.ssh: R 57016357:57016357(0) win 0 ===== * tcpdump on pflog0 For observing action from PF point of view, I set logging on these rules: SRC: ===== pass out log on $ext_if proto tcp all modulate state queue(std, tcp_ack) ===== DST: ===== block log all pass in log on $ext_if proto tcp from $src to ($ext_if) port ssh pass out log on $ext_if proto tcp from ($ext_if) port ssh to any queue (ssh_bulk ssh_login) pass in log on $ext_if proto tcp from $src to ($ext_if) port ssh queue ssh ===== So 'tcpdump -i pflog0 -nettt' shows: SRC: ===== 1. 082479 rule 19/0(match): pass out on fxp0: src-bsd.57733 > dst-bsd.22: S 2351929505:2351929505(0) win 65535 1. 087715 rule 19/0(match): pass out on fxp0: src-bsd.57734 > dst-bsd.22: S 4213894461:4213894461(0) win 65535 ===== DST: ===== 1. 010760 rule 186/0(match): pass in on fxp0: src-bsd.57733 > dst-bsd.22: S 57016355:57016355(0) win 65535 000025 rule 184/0(match): pass out on fxp0: dst-bsd.22 > src-bsd.57733: S 3006112695:3006112695(0) ack 57016356 win 65535 013247 rule 186/0(match): pass in on fxp0: src-bsd.57733 > dst-bsd.22: . ack 1 win 33304 006913 rule 186/0(match): pass in on fxp0: src-bsd.57733 > dst-bsd.22: F 1:1 (0) ack 1 win 33304 000022 rule 184/0(match): pass out on fxp0: dst-bsd.22 > src-bsd.57733: . ack 2 win 33304 012858 rule 184/0(match): pass out on fxp0: dst-bsd.22 > src-bsd.57733: P 1:40 (39) ack 2 win 33304 000324 rule 184/0(match): pass out on fxp0: dst-bsd.22 > src-bsd.57733: F 40:40(0) ack 2 win 33304 051836 rule 186/0(match): pass in on fxp0: src-bsd.57733 > dst-bsd.22: R 57016357:57016357(0) win 0 000162 rule 186/0(match): pass in on fxp0: src-bsd.57733 > dst-bsd.22: R 57016357:57016357(0) win 0 ===== Any suggestions where the packet is getting lost or how should I debug it further? -- Silver