Skip to content
This repository has been archived by the owner on Feb 26, 2020. It is now read-only.

atomic 64bit test failing on Ubuntu 10.04 LTS i686 #21

Closed
sehe opened this issue Jul 6, 2010 · 8 comments
Closed

atomic 64bit test failing on Ubuntu 10.04 LTS i686 #21

sehe opened this issue Jul 6, 2010 · 8 comments
Labels

Comments

@sehe
Copy link

sehe commented Jul 6, 2010

No problem installing spl/splat :)

The (regression) test suite fails the following testcase:

./splat -v -t 0x0b00:0x0b01

The output is nondeterministic (with the values initially veering of to the positive or the negative side of the initial value 10000000). I'm not sure what is supposed to happen, but I reckoned I'd report it first.

This is on

Q9550/8Gb

I've manually built the kernel from the Ubuntu-lts-2.6.35-6.9 tag in git://kernel.ubuntu.com/ubuntu/ubuntu-lucid.git. No further changes, and I used the stock Ubuntu config (/boot/config-2.6.32-23-generic-pae) but with CONFIG_CRYPTO_PCRYPT=y

Linux lucid 2.6.35-rc3splice+ #5 SMP Tue Jul 6 13:55:09 CEST 2010 i686 GNU/Linux
Distributor ID: Ubuntu
Description: Ubuntu 10.04 LTS
Release: 10.04
Codename: lucid

@sehe
Copy link
Author

sehe commented Jul 6, 2010

Here is a full test run (can't attach?)

SPL v0.5.0
------------------------------ Running SPLAT Tests ------------------------------
                kmem:kmem_alloc           �[0;32mPass�[0m  

          kmem_alloc: 4096 byte allocations, 10/10 successful
          kmem_alloc: 8192 byte allocations, 10/10 successful
          kmem_alloc: 16384 byte allocations, 10/10 successful
          kmem_alloc: 32768 byte allocations, 10/10 successful
          kmem_alloc: 65536 byte allocations, 10/10 successful
          kmem_alloc: 131072 byte allocations, 10/10 successful

                kmem:kmem_zalloc          �[0;32mPass�[0m  

         kmem_zalloc: 4096 byte allocations, 10/10 successful
         kmem_zalloc: 8192 byte allocations, 10/10 successful
         kmem_zalloc: 16384 byte allocations, 10/10 successful
         kmem_zalloc: 32768 byte allocations, 10/10 successful
         kmem_zalloc: 65536 byte allocations, 10/10 successful
         kmem_zalloc: 131072 byte allocations, 10/10 successful

                kmem:vmem_alloc           �[0;32mPass�[0m  

          vmem_alloc: 4096 byte allocations, 10/10 successful
          vmem_alloc: 8192 byte allocations, 10/10 successful
          vmem_alloc: 16384 byte allocations, 10/10 successful
          vmem_alloc: 32768 byte allocations, 10/10 successful
          vmem_alloc: 65536 byte allocations, 10/10 successful
          vmem_alloc: 131072 byte allocations, 10/10 successful
          vmem_alloc: 262144 byte allocations, 10/10 successful
          vmem_alloc: 524288 byte allocations, 10/10 successful
          vmem_alloc: 1048576 byte allocations, 10/10 successful
          vmem_alloc: 2097152 byte allocations, 10/10 successful
          vmem_alloc: 4194304 byte allocations, 10/10 successful

                kmem:vmem_zalloc          �[0;32mPass�[0m  

         vmem_zalloc: 4096 byte allocations, 10/10 successful
         vmem_zalloc: 8192 byte allocations, 10/10 successful
         vmem_zalloc: 16384 byte allocations, 10/10 successful
         vmem_zalloc: 32768 byte allocations, 10/10 successful
         vmem_zalloc: 65536 byte allocations, 10/10 successful
         vmem_zalloc: 131072 byte allocations, 10/10 successful
         vmem_zalloc: 262144 byte allocations, 10/10 successful
         vmem_zalloc: 524288 byte allocations, 10/10 successful
         vmem_zalloc: 1048576 byte allocations, 10/10 successful
         vmem_zalloc: 2097152 byte allocations, 10/10 successful
         vmem_zalloc: 4194304 byte allocations, 10/10 successful

                kmem:slab_small           �[0;32mPass�[0m  

          slab_small: Successfully ran ctors/dtors for 159 elements in 'kmem_test'
          slab_small: Successfully ran ctors/dtors for 159 elements in 'kmem_test'
          slab_small: Successfully ran ctors/dtors for 159 elements in 'kmem_test'

                kmem:slab_large           �[0;32mPass�[0m  

          slab_large: Successfully ran ctors/dtors for 63 elements in 'kmem_test'
          slab_large: Successfully ran ctors/dtors for 45 elements in 'kmem_test'
          slab_large: Successfully ran ctors/dtors for 31 elements in 'kmem_test'

                kmem:slab_align           �[0;32mPass�[0m  

          slab_align: Successfully ran ctors/dtors for 132 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 168 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 168 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 189 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 168 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 189 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 189 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 126 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 126 elements in 'kmem_test'
          slab_align: Successfully ran ctors/dtors for 63 elements in 'kmem_test'

                kmem:slab_reap            �[0;32mPass�[0m  

           slab_reap: kmem_test cache objects 1044, slabs 18/18 objs 1024/1044 mags 0/256 0/256 0/256 204/256 
           slab_reap: kmem_test cache objects 1044, slabs 14/18 objs 768/1044 mags 0/256 0/256 0/256 152/256 
           slab_reap: kmem_test cache objects 1044, slabs 12/18 objs 640/1044 mags 0/256 0/256 0/256 228/256 
           slab_reap: kmem_test cache objects 1044, slabs 7/18 objs 384/1044 mags 0/256 0/256 0/256 176/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 252/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 1044, slabs 5/18 objs 256/1044 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 812, slabs 5/14 objs 256/812 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 696, slabs 5/12 objs 256/696 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 406, slabs 5/7 objs 256/406 mags 0/256 0/256 0/256 256/256 
           slab_reap: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 0/256 128/256 
           slab_reap: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 0/256 128/256 
           slab_reap: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 0/256 128/256 
           slab_reap: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 0/256 128/256 
           slab_reap: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 0/256 128/256 
           slab_reap: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 0/256 128/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
           slab_reap: kmem_test cache objects 0, slabs 0/0 objs 0/0 mags 0/256 0/256 0/256 0/256 
           slab_reap: Successfully created 1024 objects in cache kmem_test and reclaimed them

                kmem:slab_age             �[0;32mPass�[0m  

            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 131080, slabs 5/2260 objs 256/131080 mags 0/256 0/256 256/256 0/256 
            slab_age: kmem_test cache objects 32322, slabs 3/5 objs 128/290 mags 0/256 0/256 128/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 128/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 128/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 128/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 3/5 objs 128/290 mags 0/256 0/256 128/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 290, slabs 0/5 objs 0/290 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 174, slabs 0/3 objs 0/174 mags 0/256 0/256 0/256 0/256 
            slab_age: kmem_test cache objects 0, slabs 0/0 objs 0/0 mags 0/256 0/256 0/256 0/256 
            slab_age: Successfully created 131072 objects in cache kmem_test and reclaimed them

                kmem:slab_lock            �[0;32mPass�[0m  

           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-16-1          0.000000000   8/7/1   808/640/32
           slab_lock: kmem_test-16-2          0.000000000   5/4/2   505/384/64
           slab_lock: kmem_test-16-4          0.003999630   5/4/4   505/384/128
           slab_lock: kmem_test-16-8          0.000000000   7/6/8   707/512/256
           slab_lock: kmem_test-16-16         0.000000000   8/7/16  808/640/512
           slab_lock: kmem_test-16-32         0.000000000   7/7/32  707/640/1024
           slab_lock: kmem_test-16-64         0.003999688   8/7/64  808/640/2048
           slab_lock: kmem_test-16-128        0.000000000   8/7/128 808/640/4096
           slab_lock: kmem_test-16-256        0.000000000   10/8/256    1010/768/8192
           slab_lock: kmem_test-16-512        0.003999723   18/16/512   1818/1536/16384
           slab_lock: kmem_test-16-1024       0.007999457   32/30/1024  3232/2944/32768
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-32-1          0.000000000   9/9/1   648/640/32
           slab_lock: kmem_test-32-2          0.000000000   9/9/2   648/640/64
           slab_lock: kmem_test-32-4          0.000000000   9/9/4   648/640/128
           slab_lock: kmem_test-32-8          0.003999699   9/9/8   648/640/256
           slab_lock: kmem_test-32-16         0.000000000   9/9/16  648/640/512
           slab_lock: kmem_test-32-32         0.000000000   9/9/32  648/640/1024
           slab_lock: kmem_test-32-64         0.000000000   9/9/64  648/640/2048
           slab_lock: kmem_test-32-128        0.003999688   9/9/128 648/640/4096
           slab_lock: kmem_test-32-256        0.000000000   13/11/256   936/768/8192
           slab_lock: kmem_test-32-512        0.007999380   23/22/512   1656/1536/16384
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-64-1          0.000000000   20/20/1 920/896/32
           slab_lock: kmem_test-64-2          0.000000000   20/20/2 920/896/64
           slab_lock: kmem_test-64-4          0.000000000   17/17/4 782/768/128
           slab_lock: kmem_test-64-8          0.003999691   14/14/8 644/640/256
           slab_lock: kmem_test-64-16         0.000000000   20/20/16    920/896/512
           slab_lock: kmem_test-64-32         0.000000000   17/17/32    782/768/1024
           slab_lock: kmem_test-64-64         0.003999697   17/17/64    782/768/2048
           slab_lock: kmem_test-64-128        0.000000000   17/17/128   782/768/4096
           slab_lock: kmem_test-64-256        0.003999708   25/23/256   1150/1024/8192
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-128-1         0.000000000   16/15/1 848/768/32
           slab_lock: kmem_test-128-2         0.003999705   13/13/2 689/640/64
           slab_lock: kmem_test-128-4         0.000000000   17/17/4 901/896/128
           slab_lock: kmem_test-128-8         0.000000000   13/13/8 689/640/256
           slab_lock: kmem_test-128-16        0.000000000   16/15/16    848/768/512
           slab_lock: kmem_test-128-32        0.003999703   16/15/32    848/768/1024
           slab_lock: kmem_test-128-64        0.000000000   17/17/64    901/896/2048
           slab_lock: kmem_test-128-128       0.003999700   17/17/128   901/896/4096
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-256-1         0.000000000   12/12/1 696/640/32
           slab_lock: kmem_test-256-2         0.000000000   16/16/2 928/896/64
           slab_lock: kmem_test-256-4         0.000000000   16/16/4 928/896/128
           slab_lock: kmem_test-256-8         0.003999697   14/14/8 812/768/256
           slab_lock: kmem_test-256-16        0.000000000   13/12/16    754/640/512
           slab_lock: kmem_test-256-32        0.000000000   13/12/32    754/640/1024
           slab_lock: kmem_test-256-64        0.003999689   13/12/64    754/640/2048
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-512-1         0.000000000   13/11/1 793/640/32
           slab_lock: kmem_test-512-2         0.000000000   13/11/2 793/640/64
           slab_lock: kmem_test-512-4         0.003999696   13/11/4 793/640/128
           slab_lock: kmem_test-512-8         0.000000000   13/11/8 793/640/256
           slab_lock: kmem_test-512-16        0.003999699   13/11/16    793/640/512
           slab_lock: kmem_test-512-32        0.000000000   13/11/32    793/640/1024
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-1024-1        0.000000000   9/6/1   558/320/32
           slab_lock: kmem_test-1024-2        0.003999705   10/7/2  620/384/64
           slab_lock: kmem_test-1024-4        0.000000000   10/7/4  620/384/128
           slab_lock: kmem_test-1024-8        0.003999703   10/7/8  620/384/256
           slab_lock: kmem_test-1024-16       0.000000000   9/6/16  558/320/512
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-2048-1        0.003999700   10/6/1  630/320/32
           slab_lock: kmem_test-2048-2        0.000000000   8/7/2   504/384/64
           slab_lock: kmem_test-2048-4        0.000000000   8/7/4   504/384/128
           slab_lock: kmem_test-2048-8        0.003999693   8/7/8   504/384/256
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-4096-1        0.000000000   6/4/1   378/192/32
           slab_lock: kmem_test-4096-2        0.000000000   6/4/2   378/192/64
           slab_lock: kmem_test-4096-4        0.000000000   6/3/4   378/160/128
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-8192-1        0.000000000   5/3/1   315/160/32
           slab_lock: kmem_test-8192-2        0.000000000   6/4/2   378/192/64
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: kmem_test-16384-1       0.003999703   6/3/1   378/160/32
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc
           slab_lock: name                    time (sec)    slabs           objs        hash
           slab_lock:                               tot/max/calc    tot/max/calc

                kmem:vmem_size            �[0;32mPass�[0m  

           vmem_size: Vmem alloc=41512960 free=84316160 total=125829120
           vmem_size: Alloc 8388608 bytes
           vmem_size: Vmem alloc=49917952 free=75911168 total=125829120
           vmem_size: Free 8388608 bytes
           vmem_size: VMEM_ALLOC within tolerance: ~0% (16384/8388608)
           vmem_size: VMEM_FREE within tolerance:  ~0% (16384/8388608)

               taskq:single               �[0;32mPass�[0m  

              single: Taskq 'single' creating
              single: Taskq 'single' function 'splat_taskq_test13_func' dispatching
              single: Taskq 'single' waiting
              single: Taskq 'single' function 'splat_taskq_test13_func' setting flag
              single: Taskq 'single' destroying

               taskq:multiple             �[0;32mPass�[0m  

            multiple: Taskq 'multiple/0' creating
            multiple: Taskq 'multiple/0' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/0' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/1' creating
            multiple: Taskq 'multiple/0' function 'splat_taskq_test2_func1' flag = 0 = 0 * 2
            multiple: Taskq 'multiple/0' function 'splat_taskq_test2_func2' flag = 1 = 0 + 1
            multiple: Taskq 'multiple/1' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/1' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/2' creating
            multiple: Taskq 'multiple/1' function 'splat_taskq_test2_func1' flag = 2 = 1 * 2
            multiple: Taskq 'multiple/1' function 'splat_taskq_test2_func2' flag = 3 = 2 + 1
            multiple: Taskq 'multiple/2' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/2' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/3' creating
            multiple: Taskq 'multiple/2' function 'splat_taskq_test2_func1' flag = 4 = 2 * 2
            multiple: Taskq 'multiple/2' function 'splat_taskq_test2_func2' flag = 5 = 4 + 1
            multiple: Taskq 'multiple/3' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/3' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/4' creating
            multiple: Taskq 'multiple/3' function 'splat_taskq_test2_func1' flag = 6 = 3 * 2
            multiple: Taskq 'multiple/3' function 'splat_taskq_test2_func2' flag = 7 = 6 + 1
            multiple: Taskq 'multiple/4' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/4' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/5' creating
            multiple: Taskq 'multiple/4' function 'splat_taskq_test2_func1' flag = 8 = 4 * 2
            multiple: Taskq 'multiple/4' function 'splat_taskq_test2_func2' flag = 9 = 8 + 1
            multiple: Taskq 'multiple/5' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/5' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/6' creating
            multiple: Taskq 'multiple/5' function 'splat_taskq_test2_func1' flag = 10 = 5 * 2
            multiple: Taskq 'multiple/5' function 'splat_taskq_test2_func2' flag = 11 = 10 + 1
            multiple: Taskq 'multiple/6' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/6' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/7' creating
            multiple: Taskq 'multiple/6' function 'splat_taskq_test2_func1' flag = 12 = 6 * 2
            multiple: Taskq 'multiple/6' function 'splat_taskq_test2_func2' flag = 13 = 12 + 1
            multiple: Taskq 'multiple/7' function 'splat_taskq_test2_func1' dispatching
            multiple: Taskq 'multiple/7' function 'splat_taskq_test2_func2' dispatching
            multiple: Taskq 'multiple/0' waiting
            multiple: Taskq 'multiple/0; destroying
            multiple: Taskq 'multiple/7' function 'splat_taskq_test2_func1' flag = 14 = 7 * 2
            multiple: Taskq 'multiple/7' function 'splat_taskq_test2_func2' flag = 15 = 14 + 1
            multiple: Taskq 'multiple/0' processed tasks in the correct order; 1 == 1
            multiple: Taskq 'multiple/1' waiting
            multiple: Taskq 'multiple/1; destroying
            multiple: Taskq 'multiple/1' processed tasks in the correct order; 3 == 3
            multiple: Taskq 'multiple/2' waiting
            multiple: Taskq 'multiple/2; destroying
            multiple: Taskq 'multiple/2' processed tasks in the correct order; 5 == 5
            multiple: Taskq 'multiple/3' waiting
            multiple: Taskq 'multiple/3; destroying
            multiple: Taskq 'multiple/3' processed tasks in the correct order; 7 == 7
            multiple: Taskq 'multiple/4' waiting
            multiple: Taskq 'multiple/4; destroying
            multiple: Taskq 'multiple/4' processed tasks in the correct order; 9 == 9
            multiple: Taskq 'multiple/5' waiting
            multiple: Taskq 'multiple/5; destroying
            multiple: Taskq 'multiple/5' processed tasks in the correct order; 11 == 11
            multiple: Taskq 'multiple/6' waiting
            multiple: Taskq 'multiple/6; destroying
            multiple: Taskq 'multiple/6' processed tasks in the correct order; 13 == 13
            multiple: Taskq 'multiple/7' waiting
            multiple: Taskq 'multiple/7; destroying
            multiple: Taskq 'multiple/7' processed tasks in the correct order; 15 == 15

               taskq:system               �[0;32mPass�[0m  

              system: Taskq 'system' function 'splat_taskq_test13_func' dispatching
              system: Taskq 'system' waiting
              single: Taskq 'system' function 'splat_taskq_test13_func' setting flag

               taskq:wait                 �[0;32mPass�[0m  

                wait: Taskq 'wait' creating
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 1 times
                wait: Taskq 'wait' waiting for 1 dispatches
                wait: Taskq 'wait' 1/1 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 2 times
                wait: Taskq 'wait' waiting for 2 dispatches
                wait: Taskq 'wait' 2/2 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 4 times
                wait: Taskq 'wait' waiting for 4 dispatches
                wait: Taskq 'wait' 4/4 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 8 times
                wait: Taskq 'wait' waiting for 8 dispatches
                wait: Taskq 'wait' 8/8 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 16 times
                wait: Taskq 'wait' waiting for 16 dispatches
                wait: Taskq 'wait' 16/16 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 32 times
                wait: Taskq 'wait' waiting for 32 dispatches
                wait: Taskq 'wait' 32/32 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 64 times
                wait: Taskq 'wait' waiting for 64 dispatches
                wait: Taskq 'wait' 64/64 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 128 times
                wait: Taskq 'wait' waiting for 128 dispatches
                wait: Taskq 'wait' 128/128 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 256 times
                wait: Taskq 'wait' waiting for 256 dispatches
                wait: Taskq 'wait' 256/256 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 512 times
                wait: Taskq 'wait' waiting for 512 dispatches
                wait: Taskq 'wait' 512/512 dispatches finished
                wait: Taskq 'wait' function 'splat_taskq_test4_func' dispatched 1024 times
                wait: Taskq 'wait' waiting for 1024 dispatches
                wait: Taskq 'wait' 1024/1024 dispatches finished
                wait: Taskq 'wait' destroying

               taskq:order                �[0;32mPass�[0m  

               order: Taskq 'order' creating
               order: Taskq 'order' waiting for taskqid 3 completion
               order: Taskqid 1 complete for taskq 'order'
               order: Taskqid 2 complete for taskq 'order'
               order: Taskqid 4 complete for taskq 'order'
               order: Taskqid 5 complete for taskq 'order'
               order: Taskqid 3 complete for taskq 'order'
               order: Taskq 'order' validated correct completion order
               order: Taskq 'order' waiting for taskqid 8 completion
               order: Taskqid 8 complete for taskq 'order'
               order: Taskqid 6 complete for taskq 'order'
               order: Taskqid 7 complete for taskq 'order'
               order: Taskq 'order' validated correct completion order
               order: Taskq 'order' destroying

               taskq:front                �[0;32mPass�[0m  

               front: Taskq 'front' creating
               front: Taskq 'front' waiting for taskqid 8 completion
               front: Taskqid 1 complete for taskq 'front'
               front: Taskqid 2 complete for taskq 'front'
               front: Taskqid 3 complete for taskq 'front'
               front: Taskqid 6 complete for taskq 'front'
               front: Taskqid 7 complete for taskq 'front'
               front: Taskqid 8 complete for taskq 'front'
               front: Taskqid 4 complete for taskq 'front'
               front: Taskqid 5 complete for taskq 'front'
               front: Taskq 'front' validated correct completion order
               front: Taskq 'front' destroying

                krng:freq                 �[0;32mPass�[0m  

Test 1 Number of ones: 524223
Test 1 Difference from expected: 65 Allowed: 2097

               mutex:tryenter             �[0;32mPass�[0m  

            tryenter: mutex_trylock() correctly failed when the mutex was held
            tryenter: mutex_trylock() correctly succeeded when the mutex was not held

               mutex:race                 �[0;32mPass�[0m  

                race: 4 racing threads correctly entered/exited the mutex 128 times

               mutex:owned                �[0;32mPass�[0m  

               owned: Correct mutex_owned() behavior

               mutex:owner                �[0;32mPass�[0m  

               owned: Correct mutex_owner() behavior

             condvar:signal1              �[0;32mPass�[0m  

             signal1: condvar_test0 thread sleeping with 0 waiters
             signal1: condvar_test1 thread sleeping with 1 waiters
             signal1: condvar_test2 thread sleeping with 2 waiters
             signal1: condvar_test3 thread sleeping with 3 waiters
             signal1: condvar_test4 thread sleeping with 4 waiters
             signal1: condvar_test5 thread sleeping with 5 waiters
             signal1: condvar_test6 thread sleeping with 6 waiters
             signal1: condvar_test7 thread sleeping with 7 waiters
             signal1: condvar_test0 thread woken 7 waiters remain
             signal1: condvar_test1 thread woken 6 waiters remain
             signal1: condvar_test2 thread woken 5 waiters remain
             signal1: condvar_test3 thread woken 4 waiters remain
             signal1: condvar_test4 thread woken 3 waiters remain
             signal1: condvar_test5 thread woken 2 waiters remain
             signal1: condvar_test6 thread woken 1 waiters remain
             signal1: condvar_test7 thread woken 0 waiters remain
             signal1: Correctly woke 8 sleeping threads 1 at a time

             condvar:broadcast1           �[0;32mPass�[0m  

          broadcast1: condvar_test0 thread sleeping with 0 waiters
          broadcast1: condvar_test1 thread sleeping with 1 waiters
          broadcast1: condvar_test2 thread sleeping with 2 waiters
          broadcast1: condvar_test3 thread sleeping with 3 waiters
          broadcast1: condvar_test4 thread sleeping with 4 waiters
          broadcast1: condvar_test5 thread sleeping with 5 waiters
          broadcast1: condvar_test6 thread sleeping with 6 waiters
          broadcast1: condvar_test7 thread sleeping with 7 waiters
          broadcast1: condvar_test1 thread woken 7 waiters remain
          broadcast1: condvar_test0 thread woken 6 waiters remain
          broadcast1: condvar_test2 thread woken 5 waiters remain
          broadcast1: condvar_test3 thread woken 4 waiters remain
          broadcast1: condvar_test4 thread woken 3 waiters remain
          broadcast1: condvar_test5 thread woken 2 waiters remain
          broadcast1: condvar_test7 thread woken 1 waiters remain
          broadcast1: condvar_test6 thread woken 0 waiters remain
          broadcast1: Correctly woke all 8 sleeping threads at once

             condvar:signal2              �[0;32mPass�[0m  

             signal2: condvar_test0 thread sleeping with 0 waiters
             signal2: condvar_test1 thread sleeping with 1 waiters
             signal2: condvar_test2 thread sleeping with 2 waiters
             signal2: condvar_test3 thread sleeping with 3 waiters
             signal2: condvar_test4 thread sleeping with 4 waiters
             signal2: condvar_test5 thread sleeping with 5 waiters
             signal2: condvar_test6 thread sleeping with 6 waiters
             signal2: condvar_test7 thread sleeping with 7 waiters
             signal2: condvar_test0 thread woken 7 waiters remain
             signal2: condvar_test1 thread woken 6 waiters remain
             signal2: condvar_test2 thread woken 5 waiters remain
             signal2: condvar_test3 thread woken 4 waiters remain
             signal2: condvar_test4 thread woken 3 waiters remain
             signal2: condvar_test5 thread woken 2 waiters remain
             signal2: condvar_test6 thread woken 1 waiters remain
             signal2: condvar_test7 thread woken 0 waiters remain
             signal2: Correctly woke 8 sleeping threads 1 at a time

             condvar:broadcast2           �[0;32mPass�[0m  

             signal2: condvar_test0 thread sleeping with 0 waiters
             signal2: condvar_test1 thread sleeping with 1 waiters
             signal2: condvar_test2 thread sleeping with 2 waiters
             signal2: condvar_test3 thread sleeping with 3 waiters
             signal2: condvar_test4 thread sleeping with 4 waiters
             signal2: condvar_test5 thread sleeping with 5 waiters
             signal2: condvar_test6 thread sleeping with 6 waiters
             signal2: condvar_test7 thread sleeping with 7 waiters
             signal2: condvar_test0 thread woken 7 waiters remain
             signal2: condvar_test1 thread woken 6 waiters remain
             signal2: condvar_test2 thread woken 5 waiters remain
             signal2: condvar_test3 thread woken 4 waiters remain
             signal2: condvar_test4 thread woken 3 waiters remain
             signal2: condvar_test5 thread woken 2 waiters remain
             signal2: condvar_test6 thread woken 1 waiters remain
             signal2: condvar_test7 thread woken 0 waiters remain
             signal2: Correctly woke 8 sleeping threads 1 at a time

             condvar:timeout              �[0;32mPass�[0m  

             timeout: Thread going to sleep for 1 second and expecting to be woken by timeout
             timeout: Thread correctly timed out and was asleep for 1.0 seconds (1 second min)

              thread:create               �[0;32mPass�[0m  

              create: Thread successfully started properly

              thread:exit                 �[0;32mPass�[0m  

                exit: Thread successfully exited at thread_exit()

              rwlock:N-rd/1-wr            �[0;32mPass�[0m  

           N-rd/1-wr: rwlock_wr_thr0 trying to acquire rwlock (0 holding/0 waiting)
           N-rd/1-wr: rwlock_wr_thr0 acquired rwlock (1 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr7 trying to acquire rwlock (1 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr1 trying to acquire rwlock (1 holding/1 waiting)
           N-rd/1-wr: rwlock_rd_thr2 trying to acquire rwlock (1 holding/2 waiting)
           N-rd/1-wr: rwlock_rd_thr6 trying to acquire rwlock (1 holding/3 waiting)
           N-rd/1-wr: rwlock_rd_thr5 trying to acquire rwlock (1 holding/3 waiting)
           N-rd/1-wr: rwlock_rd_thr3 trying to acquire rwlock (1 holding/5 waiting)
           N-rd/1-wr: rwlock_rd_thr4 trying to acquire rwlock (1 holding/6 waiting)
           N-rd/1-wr: rwlock_wr_thr0 dropped rwlock (0 holding/7 waiting)
           N-rd/1-wr: rwlock_rd_thr1 acquired rwlock (1 holding/6 waiting)
           N-rd/1-wr: rwlock_rd_thr6 acquired rwlock (2 holding/5 waiting)
           N-rd/1-wr: rwlock_rd_thr2 acquired rwlock (3 holding/4 waiting)
           N-rd/1-wr: rwlock_rd_thr3 acquired rwlock (4 holding/3 waiting)
           N-rd/1-wr: rwlock_rd_thr4 acquired rwlock (5 holding/2 waiting)
           N-rd/1-wr: rwlock_rd_thr7 acquired rwlock (6 holding/1 waiting)
           N-rd/1-wr: rwlock_rd_thr5 acquired rwlock (7 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr5 dropped rwlock (6 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr3 dropped rwlock (4 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr2 dropped rwlock (4 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr6 dropped rwlock (3 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr1 dropped rwlock (2 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr4 dropped rwlock (1 holding/0 waiting)
           N-rd/1-wr: rwlock_rd_thr7 dropped rwlock (0 holding/0 waiting)

              rwlock:0-rd/N-wr            �[0;32mPass�[0m  

           0-rd/N-wr: 4 racing threads correctly entered/exited the rwlock 256 times

              rwlock:held                 �[0;32mPass�[0m  

                held: RW_LOCK_HELD returned 1 (expected 1) when RW_READER
                held: RW_LOCK_HELD returned 0 (expected 0) when !RW_READER
                held: RW_LOCK_HELD returned 1 (expected 1) when RW_WRITER
                held: RW_LOCK_HELD returned 0 (expected 0) when !RW_WRITER
                held: RW_READ_HELD returned 1 (expected 1) when RW_READER
                held: RW_READ_HELD returned 0 (expected 0) when !RW_READER
                held: RW_READ_HELD returned 0 (expected 0) when RW_WRITER
                held: RW_READ_HELD returned 0 (expected 0) when !RW_WRITER
                held: RW_WRITE_HELD returned 0 (expected 0) when RW_READER
                held: RW_WRITE_HELD returned 0 (expected 0) when !RW_READER
                held: RW_WRITE_HELD returned 1 (expected 1) when RW_WRITER
                held: RW_WRITE_HELD returned 0 (expected 0) when !RW_WRITER

              rwlock:tryenter             �[0;32mPass�[0m  

            tryenter: rw_tryenter(RW_WRITER) returned -16 (expected -16) when RW_WRITER
            tryenter: rw_tryenter(RW_READER) returned -16 (expected -16) when RW_WRITER
            tryenter: rw_tryenter(RW_WRITER) returned -16 (expected -16) when RW_READER
            tryenter: rw_tryenter(RW_READER) returned 0 (expected 0) when RW_READER
            tryenter: rw_tryenter(RW_WRITER) returned 0 (expected 0) when RW_NONE
            tryenter: rw_tryenter(RW_READER) returned 0 (expected 0) when RW_NONE

              rwlock:rw_downgrade         �[0;32mPass�[0m  

        rw_downgrade: rwlock properly downgraded

              rwlock:rw_tryupgrade        �[0;32mPass�[0m  

       rw_tryupgrade: rw_tryupgrade() is disabled for this arch

                time:time1                �[0;32mPass�[0m  

               time1: hz is 250

                time:time2                �[0;32mPass�[0m  

               time2: time is 181045846842
               time2: time is 181045847591
               time2: time is 181084504589
               time2: time is 181124005921
               time2: time is 181164004923
               time2: time is 181204004602
               time2: time is 181244005034
               time2: time is 181284005280
               time2: time is 181324005019
               time2: time is 181364004464
               time2: time is 181404004418
               time2: time is 181444004455
               time2: time is 181484004410
               time2: time is 181524004537
               time2: time is 181564004729
               time2: time is 181604004353
               time2: time is 181644004386
               time2: time is 181684004375
               time2: time is 181724004346
               time2: time is 181764004374
               time2: time is 181804008339
               time2: time is 181844004887
               time2: time is 181884004613
               time2: time is 181924004466
               time2: time is 181964505417
               time2: time is 182004006729
               time2: time is 182044006166
               time2: time is 182084005716
               time2: time is 182124004796
               time2: time is 182164004652
               time2: time is 182204004727
               time2: time is 182244005225
               time2: time is 182284004749
               time2: time is 182324005087
               time2: time is 182364004715
               time2: time is 182404006299
               time2: time is 182444004816
               time2: time is 182484004658
               time2: time is 182524004537
               time2: time is 182564005028
               time2: time is 182604004824
               time2: time is 182644004642
               time2: time is 182684004824
               time2: time is 182724004602
               time2: time is 182764004604
               time2: time is 182804008343
               time2: time is 182844005466
               time2: time is 182884004886
               time2: time is 182924004661
               time2: time is 182964004698
               time2: time is 183004006817
               time2: time is 183044004727
               time2: time is 183084005109
               time2: time is 183124004763
               time2: time is 183164004745
               time2: time is 183204004696
               time2: time is 183244004861
               time2: time is 183284005323
               time2: time is 183324005047
               time2: time is 183364004571
               time2: time is 183404004569
               time2: time is 183444004369
               time2: time is 183484004386
               time2: time is 183524004730
               time2: time is 183564005044
               time2: time is 183604004394
               time2: time is 183644004292
               time2: time is 183684004283
               time2: time is 183724004458
               time2: time is 183764004303
               time2: time is 183804007066
               time2: time is 183844004782
               time2: time is 183884004559
               time2: time is 183924005701
               time2: time is 183964505712
               time2: time is 184004504664
               time2: time is 184044005558
               time2: time is 184084004880
               time2: time is 184124004367
               time2: time is 184164004353
               time2: time is 184204004299
               time2: time is 184244004336
               time2: time is 184284004333
               time2: time is 184324004788
               time2: time is 184364004384
               time2: time is 184404004511
               time2: time is 184444004324
               time2: time is 184484004310
               time2: time is 184524004144
               time2: time is 184564004783
               time2: time is 184604004487
               time2: time is 184644004466
               time2: time is 184684004416
               time2: time is 184724004348
               time2: time is 184764006749
               time2: time is 184804508323
               time2: time is 184844004902
               time2: time is 184884004641
               time2: time is 184924004381
               time2: time is 184964004405
               time2: time is 185004005855

               vnode:vn_open              �[0;32mPass�[0m  

             vn_open: Successfully vn_open'ed and vn_closed test file: /etc/fstab

               vnode:vn_openat            �[0;32mPass�[0m  

           vn_openat: Successfully vn_openat'ed and vn_closed test file: /etc/fstab

               vnode:vn_rdwr              �[0;32mPass�[0m  

             vn_rdwr: Wrote: SPL VNode Interface Test File
             vn_rdwr: Read:  SPL VNode Interface Test File
             vn_rdwr: Successfully wrote and read expected data pattern to test file: /tmp/spl.vnode.tmp

               vnode:vn_rename            �[0;32mPass�[0m  

           vn_rename: Wrote to /tmp/spl.vnode.tmp.1:  SPL VNode Interface Test File
           vn_rename: Read from /tmp/spl.vnode.tmp.2: SPL VNode Interface Test File
           vn_rename: Successfully renamed test file /tmp/spl.vnode.tmp.1 -> /tmp/spl.vnode.tmp.2 and verified data pattern

               vnode:vn_getattr           �[0;32mPass�[0m  

             vn_open: Successfully vn_getattr'ed test file: /etc/fstab

               vnode:vn_sync              �[0;32mPass�[0m  

             vn_sync: Successfully fsync'ed test file /tmp/spl.vnode.tmp

               vnode:vn_getf              �[0;32mPass�[0m  

             vn_rdwr: Wrote: SPL VNode Interface Test File
             vn_rdwr: Read:  SPL VNode Interface Test File
             vn_rdwr: Successfully wrote and read expected data pattern to test file: /tmp/spl.vnode.tmp

                kobj:open                 �[0;32mPass�[0m  

                open: Successfully opened and closed test file: /etc/fstab

                kobj:size/read            �[0;32mPass�[0m  

           size/read: 
# /etc/fstab: static file system information.
#
# Use 'blkid -o value -s UUID' to print the universally unique identifier
# for a device; this may be used with UUID= as a more robust way to name
# devices that works even if disks are added and removed. See fstab(5).
#
#                
proc            /proc           proc    nodev,noexec,nosuid 0       0
/dev/mapper/ssd-root /               ext4    relatime,errors=remount-ro 0       1
/dev/mapper/ssd-home /home           ext4    relatime,user_xattr        0       2
/dev/mapper/gentoo-root /mnt/gentoo/ auto    relatime,noauto,ro     0   0

none    /tmp        tmpfs mode=1777,auto,nodev 0 0
none    /var/tmp    tmpfs mode=1777,auto,nodev 0 0

sshfs#root@koolu:/ /koolu fuse comment=sshfs,noauto,users,allow_other,gid=1000,uid=1000,transform_symlinks 0 0

           size/read: Successfully stat'ed and read expected number of bytes (852) from test file: /etc/fstab

              atomic:64-bit               �[0;31mFail�[0m  Invalid argument

              64-bit: Thread 0 successfully started: 10000000/0
              64-bit: Thread 0 sleeping: 10000000/0
              64-bit: Thread 1 successfully started: 10000000/0
              64-bit: Thread 1 sleeping: 10000000/0
              64-bit: Thread 2 successfully started: 10000000/0
              64-bit: Thread 2 sleeping: 10000000/0
              64-bit: Thread 3 successfully started: 10000000/0
              64-bit: Thread 3 sleeping: 10000000/0
              64-bit: Thread 4 successfully started: 10000000/0
              64-bit: Thread 4 sleeping: 10000000/0
              64-bit: Thread 5 successfully started: 10000000/0
              64-bit: Thread 5 sleeping: 10000000/0
              64-bit: Thread 0 sleeping: 10133852/0
              64-bit: Thread 4 sleeping: 10062683/0
              64-bit: Thread 1 sleeping: 10015382/0
              64-bit: Thread 5 sleeping: 10019654/0
              64-bit: Thread 3 sleeping: 10017577/0
              64-bit: Thread 2 sleeping: 10085167/0
              64-bit: Thread 4 sleeping: 10098039/0
              64-bit: Thread 1 sleeping: 10065238/0
              64-bit: Thread 3 sleeping: 10031138/0
              64-bit: Thread 0 sleeping: 10093861/0
              64-bit: Thread 5 sleeping: 10094230/0
              64-bit: Thread 2 sleeping: 10111004/0
              64-bit: Thread 4 sleeping: 10130235/0
              64-bit: Thread 3 sleeping: 10129171/0
              64-bit: Thread 1 sleeping: 10183987/0
              64-bit: Thread 0 sleeping: 10209400/0
              64-bit: Thread 2 sleeping: 10208998/0
              64-bit: Thread 4 sleeping: 10141902/0
              64-bit: Thread 3 sleeping: 10104534/0
              64-bit: Thread 5 sleeping: 10096893/0
              64-bit: Thread 1 sleeping: 10165937/0
              64-bit: Thread 2 sleeping: 10247567/0
              64-bit: Thread 0 sleeping: 10260586/0
              64-bit: Thread 4 sleeping: 10272110/0
              64-bit: Thread 3 sleeping: 10218643/0
              64-bit: Thread 1 sleeping: 10186847/0
              64-bit: Thread 2 sleeping: 10209709/0
              64-bit: Thread 5 sleeping: 10209281/0
              64-bit: Thread 0 sleeping: 10227861/0
              64-bit: Thread 4 sleeping: 10282498/0
              64-bit: Thread 1 sleeping: 10282696/0
              64-bit: Thread 3 sleeping: 10292974/0
              64-bit: Thread 2 sleeping: 10335085/0
              64-bit: Thread 0 sleeping: 10310707/0
              64-bit: Thread 4 sleeping: 10325450/0
              64-bit: Thread 5 sleeping: 10323880/0
              64-bit: Thread 3 sleeping: 10323420/0
              64-bit: Thread 2 sleeping: 10432823/0
              64-bit: Thread 0 sleeping: 10454403/0
              64-bit: Thread 1 sleeping: 10455606/0
              64-bit: Thread 4 sleeping: 10457210/0
              64-bit: Thread 3 sleeping: 10378066/0
              64-bit: Thread 5 sleeping: 10398203/0
              64-bit: Thread 2 sleeping: 10398315/0
              64-bit: Thread 1 sleeping: 10424996/0
              64-bit: Thread 4 sleeping: 10492287/0
              64-bit: Thread 3 sleeping: 10445620/0
              64-bit: Thread 0 sleeping: 10441626/0
              64-bit: Thread 2 sleeping: 10439610/0
              64-bit: Thread 5 sleeping: 10401799/0
              64-bit: Thread 1 sleeping: 10453712/0
              64-bit: Thread 4 successfully exited: 10454032/1
              64-bit: Thread 3 successfully exited: 10427788/2
              64-bit: Thread 2 successfully exited: 10409198/3
              64-bit: Thread 0 sleeping: 10400557/3
              64-bit: Thread 5 sleeping: 10357213/3
              64-bit: Thread 1 successfully exited: 10321540/4
              64-bit: Thread 5 sleeping: 10023114/4
              64-bit: Thread 0 successfully exited: 10056266/5
              64-bit: Thread 5 successfully exited: 9556266/6
              64-bit: Final value 9556266 does not match initial value 10000000

                list:create/destroy       �[0;32mPass�[0m  

      create/destroy: Creating list
      create/destroy: Destroying list

                list:ins/rm head          �[0;32mPass�[0m  

         ins/rm head: Creating list
         ins/rm head: Adding 8 items to list head
         ins/rm head: Validating 8 item list is a stack
         ins/rm head: Removing 8 items from list head
         ins/rm head: Destroying list

                list:ins/rm tail          �[0;32mPass�[0m  

         ins/rm tail: Creating list
         ins/rm tail: Adding 8 items to list tail
         ins/rm tail: Validating 8 item list is a queue
         ins/rm tail: Removing 8 items from list tail
         ins/rm tail: Destroying list

                list:insert_after         �[0;32mPass�[0m  

        insert_after: Creating list
        insert_after: Adding 8 items each after the last item
        insert_after: Validating 8 item list is a queue
        insert_after: Removing 8 items from list tail
        insert_after: Destroying list

                list:insert_before        �[0;32mPass�[0m  

       insert_before: Creating list
       insert_before: Adding 8 items each before the last item
       insert_before: Validating 8 item list is a queue
       insert_before: Removing 8 items from list tail
       insert_before: Destroying list

                list:remove               �[0;32mPass�[0m  

              remove: Creating list
              remove: Adding 8 items to list tail
              remove: Removing 4 odd items from the list
              remove: Validating 4 item list is a queue of only even elements
              remove: Removing 4 items from list tail
              remove: Destroying list

                list:active               �[0;32mPass�[0m  

              active: Creating list
              active: Init list node
              active: Insert list node
              active: Remove list node
              active: Destroying list

             generic:ddi_strtoul          �[0;32mPass�[0m  

         ddi_strtoul: Pass (0) positive: 123456789 == 123456789, 0xf87c6373
         ddi_strtoul: Pass (0) negative: -123456789 == 0, 0xededbe74
         ddi_strtoul: Pass (0) base: 0xabcdef == 11259375, 0xf87c6399
         ddi_strtoul: Pass (34) max: 10000000000000000 == 0, 0x(null)
         ddi_strtoul: Pass (0) min: -10000000000000000 == 0, 0xededbe74
         ddi_strtoul: Pass (0) invalid: 12345U == 12345, 0xf87c63d1
         ddi_strtoul: Pass (0) invalid: invald == 0, 0xededbe74

             generic:ddi_strtol           �[0;32mPass�[0m  

         ddi_strtoul: Pass (0) positive: 123456789 == 123456789, 0xf87c6373
         ddi_strtoul: Pass (0) negative: -123456789 == -123456789, 0xededbe7e
         ddi_strtoul: Pass (0) base: 0xabcdef == 11259375, 0xf87c6399
         ddi_strtoul: Pass (34) max: 10000000000000000 == 0, 0x(null)
         ddi_strtoul: Pass (34) min: -10000000000000000 == 0, 0x(null)
         ddi_strtoul: Pass (0) invalid: 12345U == 12345, 0xf87c63d1
         ddi_strtoul: Pass (0) invalid: invald == 0, 0xededbe74

             generic:ddi_strtoull         �[0;32mPass�[0m  

         ddi_strtoul: Pass (0) positive: 123456789 == 123456789, 0xf87c6373
         ddi_strtoul: Pass (0) negative: -123456789 == 0, 0xededbe74
         ddi_strtoul: Pass (0) base: 0xabcdef == 11259375, 0xf87c6399
         ddi_strtoul: Pass (34) max: 10000000000000000 == 0, 0x(null)
         ddi_strtoul: Pass (0) min: -10000000000000000 == 0, 0xededbe74
         ddi_strtoul: Pass (0) invalid: 12345U == 12345, 0xf87c63d1
         ddi_strtoul: Pass (0) invalid: invald == 0, 0xededbe74

             generic:ddi_strtoll          �[0;32mPass�[0m  

         ddi_strtoul: Pass (0) positive: 123456789 == 123456789, 0xf87c6373
         ddi_strtoul: Pass (0) negative: -123456789 == -123456789, 0xededbe7e
         ddi_strtoul: Pass (0) base: 0xabcdef == 11259375, 0xf87c6399
         ddi_strtoul: Pass (34) max: 10000000000000000 == 0, 0x(null)
         ddi_strtoul: Pass (34) min: -10000000000000000 == 0, 0x(null)
         ddi_strtoul: Pass (0) invalid: 12345U == 12345, 0xf87c63d1
         ddi_strtoul: Pass (0) invalid: invald == 0, 0xededbe74

                cred:cred                 �[0;32mPass�[0m  

                cred: uid: 0 ruid: 0 suid: 0 gid: 0 rgid: 0 sgid: 0
                cred: ngroups: 2 groups: 0 29 
                cred: Success sane CRED(): 0

                cred:kcred                �[0;32mPass�[0m  

               kcred: uid: 0 ruid: 0 suid: 0 gid: 0 rgid: 0 sgid: 0
               kcred: ngroups: 0 groups: 
               kcred: Success sane kcred: 0

                cred:groupmember          �[0;32mPass�[0m  

         groupmember: Success root gid is a member of the expected groups: 0

@sehe
Copy link
Author

sehe commented Jul 6, 2010

Extra info:

sehe@lucid:~/custom/spl$ egrep -ni 'ATOMIC|64' spl_config.h

4:/* Atomic types use spinlocks */
5:/* #undef ATOMIC_SPINLOCK */
37:/* kernel defines atomic64_cmpxchg */
38:#define HAVE_ATOMIC64_CMPXCHG 1
40:/* kernel defines atomic64_t */
41:#define HAVE_ATOMIC64_T 1
43:/* kernel defines atomic64_xchg */
44:#define HAVE_ATOMIC64_XCHG 1
61:/* div64_64() is available */
62:/* #undef HAVE_DIV64_64 */
64:/* div64_u64() is available */
65:#define HAVE_DIV64_U64 1
79:/* fls64() is available */
80:#define HAVE_FLS64 1

@sehe
Copy link
Author

sehe commented Jul 6, 2010

After enabling CONFIG_ATOMIC64_SELFTEST=y in the kernel config, this snippet is from early dmesg:

[    0.060615] CPU0: Intel(R) Core(TM)2 Quad CPU    Q9550  @ 2.83GHz stepping 0a
[    0.064000] APIC calibration not consistent with PM-Timer: 115ms instead of 100ms
[    0.064000] APIC delta adjusted to PM-Timer: 2083329 (2416624)
[    0.064000] Booting Node   0, Processors  #1
[    0.008000] Initializing CPU#1
[    0.152074]  #2
[    0.008000] Initializing CPU#2
[    0.244066]  #3 Ok.
[    0.008000] Initializing CPU#3
[    0.336007] Brought up 4 CPUs
[    0.336010] Total of 4 processors activated (22665.84 BogoMIPS).
[    0.338344] devtmpfs: initialized
[    0.338344] atomic64 test passed for i586+ platform with CX8 and with SSE
[    0.338344] regulator: core version 0.5

@sehe
Copy link
Author

sehe commented Jul 6, 2010

I've confirmed it is down to the atomicity/concurrency per se (if you're interested I have a patch that pushes the limits on the arithmetic side a bit verifying that no thing like signed/unsigned conflict or integer over-/underflow was subverting the math).

As expected, manually defining #define ATOMIC_SPINLOCK 1 in spl_config.h makes the test pass, albeit over 4 times as slow (2s+ instead of 0.5s)

@behlendorf
Copy link
Contributor

If you're interested I have a patch that pushes the limits on the arithmetic side a
bit verifying that no thing like signed/unsigned conflict or integer over-/underflow
was subverting the math.

I'd love it if you could provide a patch which adds additional regression tests to the atomic subsystem. Catching the sort of issue you discovered is absolutely the reason why I bother write all these regression tests.

As expected, manually defining #define ATOMIC_SPINLOCK 1 in spl_config.h
makes the test pass,

Good, good I was going to ask if you tried that. I don't see any similar issue with my i686 Ubuntu 10.04 LTS version which based on the default 2.6.32 kernel. So I suspect this was caused by a kernel change in the newer releases. Can you check the following are defined in spl_config.h.

#define HAVE_ATOMIC64_CMPXCHG 1
#define HAVE_ATOMIC64_T 1
#define HAVE_ATOMIC64_XCHG 1

@sehe
Copy link
Author

sehe commented Jul 7, 2010

Cleanup from my second comment:

38: #define HAVE_ATOMIC64_CMPXCHG 1
41: #define HAVE_ATOMIC64_T 1
44: #define HAVE_ATOMIC64_XCHG 1
65: #define HAVE_DIV64_U64 1
80: #define HAVE_FLS64 1

@sehe
Copy link
Author

sehe commented Jul 7, 2010

I'd love it if you could provide a patch which adds additional regression tests to the atomic subsystem. Catching the sort of issue you discovered is absolutely the reason why I bother write all these regression tests.

I didn't really have any relevant additions. I just had some modifications to

  1. made the threads run sequentially rather than simultaneously (so I could prove that the operations in itself yield correct results)
  2. isolated op-tests (so I could verify that all operations are equally broken... :))
  3. reordered the test cases so all 'subtractions' precede the 'additions' - in case there was some kind of underflow/two's complement issue going on
  4. increase the delta (so I could verify that over/underflow was not a problem)

All checks panned out just as expected, which is why I concluded that the concurrency in itself is causing the corruption

@behlendorf
Copy link
Contributor

Closing this issue as stale, I've had no additional reports of this in over a year.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

2 participants