From owner-freebsd-current@FreeBSD.ORG Fri Feb 27 13:53:45 2004 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 02F7716A4CE for ; Fri, 27 Feb 2004 13:53:45 -0800 (PST) Received: from smtp3b.sentex.ca (smtp3b.sentex.ca [205.211.164.50]) by mx1.FreeBSD.org (Postfix) with ESMTP id 4BDF743D1F for ; Fri, 27 Feb 2004 13:53:42 -0800 (PST) (envelope-from mike@sentex.net) Received: from avscan2.sentex.ca (avscan2.sentex.ca [199.212.134.19]) by smtp3b.sentex.ca (8.12.10/8.12.10) with ESMTP id i1RLqs3Z093055; Fri, 27 Feb 2004 16:52:54 -0500 (EST) (envelope-from mike@sentex.net) Received: from localhost (localhost [127.0.0.1]) by avscan2.sentex.ca (Postfix) with ESMTP id 2379159CD5; Fri, 27 Feb 2004 16:53:21 -0500 (EST) Received: from avscan2.sentex.ca ([127.0.0.1]) by localhost (avscan2.sentex.ca [127.0.0.1]) (amavisd-new, port 10024) with SMTP id 00326-04; Fri, 27 Feb 2004 16:53:20 -0500 (EST) Received: from lava.sentex.ca (pyroxene.sentex.ca [199.212.134.18]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by avscan2.sentex.ca (Postfix) with ESMTP id C9A0759CB6; Fri, 27 Feb 2004 16:53:20 -0500 (EST) Received: from simian.sentex.net ([192.168.43.27]) by lava.sentex.ca (8.12.9p2/8.12.9) with ESMTP id i1RLrHZa016923; Fri, 27 Feb 2004 16:53:18 -0500 (EST) (envelope-from mike@sentex.net) Message-Id: <6.0.3.0.0.20040227162418.094894c0@209.112.4.2> X-Sender: mdtpop@209.112.4.2 (Unverified) X-Mailer: QUALCOMM Windows Eudora Version 6.0.3.0 Date: Fri, 27 Feb 2004 16:52:43 -0500 To: freebsd-current@freebsd.org From: Mike Tancsa In-Reply-To: <6.0.1.1.0.20040119171231.083aa710@209.112.4.2> References: <200401191300.13506.john@johnrshannon.com> <6.0.1.1.0.20040119150706.065979c0@209.112.4.2> <200401191352.09399.sam@errno.com> <6.0.1.1.0.20040119165441.0838ee10@209.112.4.2> <6.0.1.1.0.20040119171231.083aa710@209.112.4.2> Mime-Version: 1.0 Content-Type: text/plain; charset="us-ascii"; format=flowed X-Virus-Scanned: by amavisd-new X-Virus-Scanned: by amavisd-new at (avscan2) sentex.ca X-Mailman-Approved-At: Sat, 28 Feb 2004 05:23:01 -0800 Subject: Re: VPN 1401 problem (hifn driver) X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 27 Feb 2004 21:53:45 -0000 Is there anyone out there using the Soekris VPN1401 card ? I have a batch of 3 that all show the same behaviour that the 1201s do not and I just want to make sure its not a bad batch Basically, I create a large file ( cat /dev/urandom > big ) and then do the following. openssl enc -des3 -in big -k p | ssh mdtancsa@192.168.43.210 "cat - > /home/mdtancsa/b.out" The ssh session is also des3. It will proceed along for some variable amount of time and then will hang, until a generate some crypto traffic (that is accelerated) in another process. e.g. in another ssh session that is aes or 3des, I just enter, and all of a sudden openssl continues on. I first ran into it on RELENG_4 and someone suggested that it might be a RELENG_4 issue so I have now built a 5.x box but I see the same results. Its pretty easy to reproduce with no debugging, but if I set hw.hifn.debug to 1, it becomes much more rare. ---Mike At 05:12 PM 19/01/2004, Mike Tancsa wrote: >OK, got it. Here are the last lines leading up to the hang > >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 2/47/47/2 k 1/46/46/1 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 5/5 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 3/52/52/3 k 2/47/47/2 u 1/5/5/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 4/53/53/4 k 3/52/52/3 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 5/54/54/5 k 4/53/53/4 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 6/55/55/6 k 5/54/54/5 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 7/56/56/7 k 6/55/55/6 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 5/5 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 8/61/61/8 k 7/56/56/7 u 1/5/5/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 9/62/62/9 k 8/61/61/8 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 10/63/63/10 k 9/62/62/9 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 11/64/64/11 k 10/63/63/10 u 1/1/1/1 >Jan 19 17:09:49 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >22322022 u 0/0/0/0 n 1/1 >Jan 19 17:09:49 pp-duke /kernel: load res >Jan 19 17:09:49 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >Jan 19 17:09:49 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >damier 22322022 i 12/65/65/12 k 11/64/64/11 u 1/1/1/1 > >At 05:08 PM 19/01/2004, Mike Tancsa wrote: >>At 04:52 PM 19/01/2004, Sam Leffler wrote: >>>On Monday 19 January 2004 01:26 pm, Mike Tancsa wrote: >>> >>> > ... and then it just stalls. If I then hit enter in the 3des >>> encrypted ssh >>> > session or do something that talks to /dev/crypto, it goes again for a >>> > seeming random period of time. It seems to pick up exactly where it >>> should. >>> > The next lines being, >>> >>>The freebsd driver has debugging support if (compiled properly). If you do >>> >>>sysctl hw.hifn.debug=1 >>> >>>you'll get msgs on the console. Unfortnately this will probably perturb >>>your >>>test too much but if the hang is for a long time you might be able to >>>turn it >>>on just then. I suspect you'll find that the backgrond polling to collect >>>entropy for the system RNG is prodding whatever is stuck. >> >> >>If I wait for the hang and enable it there is no output. I then prod the >>system by doing /usr/src/tools/tools/crypto/cryptotest -z 1 >>its starts yammering away big time. I am still trying to capture it with >>debugging enabled prior to its hang. I will keep trying from home tonight. >> >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 88884c4c ien >>22322022 u 0/0/1/1 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 1/19/19/1 k 24/18/17/23 u 1/1/2/2 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 2/20/20/2 k 1/19/19/1 u 1/1/1/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 3/3 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 3/23/23/3 k 2/20/20/2 u 1/3/3/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 4/24/24/4 k 3/23/23/3 u 1/1/1/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 5/25/25/5 k 4/24/24/4 u 1/1/1/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 6/26/26/6 k 5/25/25/5 u 1/1/1/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 7/27/27/7 k 6/26/26/6 u 1/1/1/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 8/28/28/8 k 7/27/27/7 u 1/1/1/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 9/29/29/9 k 8/28/28/8 u 1/1/1/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier >>2232202322022 i 1/49/49/1 k 24/44/44/24 u 1/5/5/1 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:40 pp-duke /kernel: load res >>Jan 19 16:55:40 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:40 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 2/50/50/2 k 1/49/49/1 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 3/51/51/3 k 2/50/50/2 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 4/52/52/4 k 3/51/51/3 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 5/53/53/5 k 4/52/52/4 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifc ien 22322022 damier 22322022 i >>21/77/77/21 k 20/76/76/20 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 22/78/78/22 k 21/77/77/21 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 5/5 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 23/83/83/23 k 22/78/78/22 u 1/5/5/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 24/0/0/24 k 23/83/83/23 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 1/1/1/1 k 24/84/84/24 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn08/30/30/18 k 17/25/25/17 u 1/5/5/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 19/31/31/19 k 18/30/30/18 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: irq: stat 8c988c8c ien 22322022 >>damier 22322022 i 20/32/32/20 k 19/31/31/19 u 1/1/1/1 >>Jan 19 16:55:41 pp-duke /kernel: hifn0: Entering cmd: stat 8c888c8c ien >>22322022 u 0/0/0/0 n 1/1 >>Jan 19 16:55:41 pp-duke /kernel: load res >>Jan 19 16:55:41 pp-duke /kernel: hifn0: command: stat 8c888c8c ier 22322022