Re: VPN 1401 problem (hifn driver)

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_at_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