Hello,
I am testing a GLDv3 driver running on Solaris10. The driver's tx performance
needs more improvement.
After started netperf transmission test for a few seconds, I run lockstat to
see what it is busy with. Surprisingly, I see a lot of page_hashin /
page_hashout, kmem_slab_alloc/kmem_slab_free functions get called and they
wasted a lot of time. Then I run a simple dtrace script to see who called these
functions. It looks like the caller is from the OS, not the driver. I also
tested Intel 10G card but did not see any of these functions on top of the
lockstat result.
I am wondering why OS spends so much time to do memory allocation &
de-allocation for this driver?
Tom
-bash-3.00# more lock.txt
Adaptive mutex spin: 902163 events in 20.146 seconds (44781 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
181428 20% 20% 0.00 11987 vph_mutex+0x8000 page_hashout+0xc4
140110 16% 36% 0.00 13197 vph_mutex+0x8000 page_hashin+0x7c
54690 6% 42% 0.00 9225 0x3000026c0e0 kmem_slab_alloc+0x8
50524 6% 47% 0.00 9447 0x3000026c0e0 kmem_slab_free+0x14
47132 5% 53% 0.00 10129 0x3000026c0e0 kmem_slab_alloc+0x4c
33470 4% 56% 0.00 5589 0x30000008db8 vmem_alloc+0x118
32499 4% 60% 0.00 6296 0x30000008020 vmem_xfree+0xc
31983 4% 63% 0.00 5563 0x300b5cdedb8 vmem_xalloc+0x1a4
31432 3% 67% 0.00 5539 0x30000008020 vmem_alloc+0x118
28541 3% 70% 0.00 5331 0x300b5cdedb8 vmem_xfree+0xc
26722 3% 73% 0.00 5499 0x30000008db8 vmem_xfree+0xc
26272 3% 76% 0.00 5212 0x30000008db8 vmem_xalloc+0x614
25731 3% 79% 0.00 7190 0x30000008020 vmem_xalloc+0x614
23976 3% 81% 0.00 18757 0x3a37e7b48b8 qlcnic_send_mapped+0x7b8
13764 2% 83% 0.00 5659 0x300b64a40e0 kmem_slab_alloc+0x8
12712 1% 84% 0.00 6309 0x300b64a40e0 kmem_slab_free+0x14
9074 1% 85% 0.00 4140 vmem0+0x20 vmem_xfree+0xc
8621 1% 86% 0.00 9901 0x30000008db8 vmem_xalloc+0x1a4
8099 1% 87% 0.00 12019 0x300003046c0 kmem_log_enter+0x48
6984 1% 88% 0.00 5189 vmem0+0x20 vmem_nextfit_alloc+0x10
6028 1% 89% 0.00 10677 0x30000008020 vmem_xalloc+0x1a4
3837 0% 89% 0.00 3898 0x70049a2d408 page_ctr_sub+0x44
3773 0% 89% 0.00 3806 0x70049a2d408 page_ctr_add+0x44
3557 0% 90% 0.00 4287 0x3a37e7b48b8
qlcnic_process_cmd_ring+0x30
Intel 10G card lockstat result:
Adaptive mutex spin: 47618 events in 20.064 seconds (2373 events/sec)
Count indv cuml rcnt nsec Lock Caller
-------------------------------------------------------------------------------
5744 12% 12% 0.00 1646 0x6003684b240 soft_ring_process+0x4
3775 8% 20% 0.00 3005 0x6003684b900 soft_ring_process+0x4
3687 8% 28% 0.00 5726 0x300023c2198 kmem_depot_alloc+0x1c
2093 4% 32% 0.00 4176 0x6003684ba80 soft_ring_process+0x4
1232 3% 35% 0.00 11452 0x30000121240 kmem_cache_free+0x108
1011 2% 37% 0.00 4314 0x6003fe44280 tcp_wput+0xa0
917 2% 39% 0.00 4713 0x300023c2198 kmem_depot_free+0x8
894 2% 41% 0.00 1018 0x6003684b240 soft_ring_drain+0x80
883 2% 42% 0.00 5094 0x6003fe44280 ipcl_classify_v4+0x1d0
819 2% 44% 0.00 4370 0x60031ee5480 squeue_enter+0x10
815 2% 46% 0.00 11161 0x3000231b240 kmem_cache_free+0x108
809 2% 48% 0.00 11356 0x300083ab240 kmem_cache_free+0x108
801 2% 49% 0.00 4749 0x6003684b240 soft_ring_worker+0x11c
711 1% 51% 0.00 2588 0x6003fe448d8 tcp_wput_data+0x9fc
698 1% 52% 0.00 997 0x6003684b900 soft_ring_drain+0x80
653 1% 54% 0.00 11345 0x30000121380 kmem_cache_free+0x108
598 1% 55% 0.00 4379 0x6003fe448d8 tcp_wput+0x64
Dtrace results:
0 9257 kmem_slab_alloc:entry
genunix`kmem_cache_alloc+0x290
genunix`allocb+0x94
genunix`allocb_cred+0x8
genunix`mcopyinuio+0x94
sockfs`sostream_direct+0x140
sockfs`sotpi_sendmsg+0x4e8
sockfs`sendit+0x134
sockfs`send+0x60
unix`syscall_trap32+0xcc
0 5550 page_hashin:entry
unix`page_create_va+0x488
unix`segkmem_page_create+0x84
unix`segkmem_xalloc+0xb0
unix`segkmem_alloc_vn+0xc0
genunix`vmem_xalloc+0x608
genunix`vmem_alloc+0x1d4
genunix`kmem_slab_create+0x44
genunix`kmem_slab_alloc+0x30
genunix`kmem_cache_alloc+0x290
genunix`allocb+0x94
genunix`allocb_cred+0x8
genunix`mcopyinuio+0x94
sockfs`sostream_direct+0x140
sockfs`sotpi_sendmsg+0x4e8
sockfs`sendit+0x134
sockfs`send+0x60
unix`syscall_trap32+0xcc
0 5550 page_hashin:entry
unix`page_create_va+0x488
unix`segkmem_page_create+0x84
unix`segkmem_xalloc+0xb0
unix`segkmem_alloc_vn+0xc0
genunix`vmem_xalloc+0x608
genunix`vmem_alloc+0x1d4
genunix`kmem_slab_create+0x44
genunix`kmem_slab_alloc+0x30
genunix`kmem_cache_alloc+0x290
genunix`allocb+0x94
genunix`allocb_cred+0x8
genunix`mcopyinuio+0x94
sockfs`sostream_direct+0x140
sockfs`sotpi_sendmsg+0x4e8
^C unix`page_create_va+0x488
unix`segkmem_page_create+0x84
unix`segkmem_xalloc+0xb0
unix`segkmem_alloc_vn+0xc0
genunix`vmem_xalloc+0x608
genunix`vmem_alloc+0x1d4
genunix`kmem_slab_create+0x44
genunix`kmem_slab_alloc+0x30
genunix`kmem_cache_alloc+0x290
genunix`allocb+0x94
genunix`allocb_cred+0x8
genunix`mcopyinuio+0x94
sockfs`sostream_direct+0x140
sockfs`sotpi_sendmsg+0x4e8
sockfs`sendit+0x134
sockfs`send+0x60
unix`syscall_trap32+0xcc
--
This message posted from opensolaris.org
_______________________________________________
networking-discuss mailing list
networking-discuss@opensolaris.org
