Skip to content

Instantly share code, notes, and snippets.

@hiboma
Last active August 29, 2015 13:57
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save hiboma/9865994 to your computer and use it in GitHub Desktop.
Save hiboma/9865994 to your computer and use it in GitHub Desktop.
perf 計測生データ
perf 計測生データ
* perf record -p <pid> で profile を取る
* bash と sshd を対象とする
* sshd は TCPソケットでホストOSからのパケットを受け取ってシェルプロンプトに文字を書くのを請け負っている
* ネットワーク割り込みが直接関係するのは、たぶん、sshd
* エンターキー押しっぱなし、適当なキーを押しっぱなしにしてる状態の profile を取る
@hiboma
Copy link
Author

hiboma commented Mar 30, 2014

sshd + /proc/irq/19/smp_affinity が f (デフォルト)

# ========
# captured on: Sun Mar 30 01:48:35 2014
# hostname : vagrant-centos65.vagrantup.com
# os release : 2.6.32-431.el6.x86_64
# perf version : 2.6.32-431.11.2.el6.x86_64.debug
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i7-4558U CPU @ 2.80GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 603168 kB
# cmdline : /usr/bin/perf record -p 1729 -o f-sshd.raw 
# event : name = cpu-clock, type = 1, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, id = { 56 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: tracepoint = 2, software = 1
# ========
#
# Samples: 828  of event 'cpu-clock'
# Event count (approx.): 828
#
# Overhead  Command        Shared Object                                 Symbol
# ........  .......  ...................  .....................................
#
    25.12%     sshd  [kernel.kallsyms]    [k] _spin_unlock_irqrestore          
    11.84%     sshd  libcrypto.so.1.0.1e  [.] vpaes_encrypt                    
    10.75%     sshd  [kernel.kallsyms]    [k] finish_task_switch               
    10.14%     sshd  sshd                 [.] 0x000000000004a25d               
     6.04%     sshd  libcrypto.so.1.0.1e  [.] 0x00000000000e3671               
     3.02%     sshd  [kernel.kallsyms]    [k] iowrite16                        
     1.57%     sshd  libz.so.1.2.3        [.] 0x00000000000046e2               
     1.57%     sshd  [kernel.kallsyms]    [k] __do_softirq                     
     1.33%     sshd  [kernel.kallsyms]    [k] do_select                        
     1.33%     sshd  [kernel.kallsyms]    [k] ioread8                          
     1.21%     sshd  [kernel.kallsyms]    [k] copy_user_generic_string         
     0.97%     sshd  libc-2.12.so         [.] memcpy                           
     0.97%     sshd  libc-2.12.so         [.] __GI___libc_read                 
     0.97%     sshd  [kernel.kallsyms]    [k] sys_rt_sigprocmask               
     0.72%     sshd  libc-2.12.so         [.] sigemptyset                      
     0.72%     sshd  [kernel.kallsyms]    [k] pipe_poll                        
     0.60%     sshd  libc-2.12.so         [.] __select                         
     0.60%     sshd  [kernel.kallsyms]    [k] sigprocmask                      
     0.60%     sshd  [kernel.kallsyms]    [k] __audit_syscall_exit             
     0.60%     sshd  [kernel.kallsyms]    [k] fsnotify                         
     0.60%     sshd  [kernel.kallsyms]    [k] tcp_recvmsg                      
     0.48%     sshd  [kernel.kallsyms]    [k] unroll_tree_refs                 
     0.48%     sshd  [kernel.kallsyms]    [k] kfree                            
     0.48%     sshd  [kernel.kallsyms]    [k] rw_verify_area                   
     0.48%     sshd  [kernel.kallsyms]    [k] vfs_read                         
     0.48%     sshd  [kernel.kallsyms]    [k] inet_recvmsg                     
     0.48%     sshd  [kernel.kallsyms]    [k] thread_return                    
     0.36%     sshd  libz.so.1.2.3        [.] inflate                          
     0.36%     sshd  libc-2.12.so         [.] __write_nocancel                 
     0.36%     sshd  [kernel.kallsyms]    [k] local_bh_enable                  
     0.36%     sshd  [kernel.kallsyms]    [k] security_socket_recvmsg          
     0.36%     sshd  [kernel.kallsyms]    [k] n_tty_poll                       
     0.36%     sshd  [kernel.kallsyms]    [k] tcp_poll                         
     0.36%     sshd  [kernel.kallsyms]    [k] _spin_lock_irqsave               
     0.24%     sshd  sshd                 [.] sigemptyset@plt                  
     0.24%     sshd  libz.so.1.2.3        [.] adler32                          
     0.24%     sshd  libz.so.1.2.3        [.] deflate                          
     0.24%     sshd  libz.so.1.2.3        [.] _tr_flush_block                  
     0.24%     sshd  libcrypto.so.1.0.1e  [.] md5_block_asm_data_order         
     0.24%     sshd  libcrypto.so.1.0.1e  [.] RAND_bytes                       
     0.24%     sshd  libcrypto.so.1.0.1e  [.] EVP_CIPHER_CTX_get_app_data      
     0.24%     sshd  libcrypto.so.1.0.1e  [.] EVP_Cipher                       
     0.24%     sshd  libc-2.12.so         [.] __errno_location                 
     0.24%     sshd  libc-2.12.so         [.] __memset_sse2                    
     0.24%     sshd  [virtio_ring]        [k] virtqueue_get_buf                
     0.24%     sshd  [kernel.kallsyms]    [k] system_call                      
     0.24%     sshd  [kernel.kallsyms]    [k] lock_timer_base                  
     0.24%     sshd  [kernel.kallsyms]    [k] current_kernel_time              
     0.24%     sshd  [kernel.kallsyms]    [k] sys_read                         
     0.24%     sshd  [kernel.kallsyms]    [k] fput                             
     0.24%     sshd  [kernel.kallsyms]    [k] __pollwait                       
     0.24%     sshd  [kernel.kallsyms]    [k] core_sys_select                  
     0.24%     sshd  [kernel.kallsyms]    [k] inotify_inode_queue_event        
     0.24%     sshd  [kernel.kallsyms]    [k] security_file_permission         
     0.24%     sshd  [kernel.kallsyms]    [k] cap_socket_recvmsg               
     0.24%     sshd  [kernel.kallsyms]    [k] tty_poll                         
     0.24%     sshd  [kernel.kallsyms]    [k] n_tty_read                       
     0.24%     sshd  [kernel.kallsyms]    [k] pty_write_room                   
     0.24%     sshd  [kernel.kallsyms]    [k] tty_audit_add_data               
     0.24%     sshd  [kernel.kallsyms]    [k] dev_queue_xmit                   
     0.24%     sshd  [kernel.kallsyms]    [k] sk_run_filter                    
     0.24%     sshd  [kernel.kallsyms]    [k] ip_route_input                   
     0.24%     sshd  [kernel.kallsyms]    [k] tcp_cleanup_rbuf                 
     0.24%     sshd  [kernel.kallsyms]    [k] __tcp_select_window              
     0.24%     sshd  [kernel.kallsyms]    [k] packet_rcv                       
     0.12%     sshd  libz.so.1.2.3        [.] adler32@plt                      
     0.12%     sshd  libcrypto.so.1.0.1e  [.] CRYPTO_lock                      
     0.12%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Final                       
     0.12%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Init                        
     0.12%     sshd  libcrypto.so.1.0.1e  [.] FIPS_selftest_check              
     0.12%     sshd  libc-2.12.so         [.] free                             
     0.12%     sshd  [virtio_net]         [k] xmit_skb                         
     0.12%     sshd  [virtio_net]         [k] start_xmit                       
     0.12%     sshd  [kernel.kallsyms]    [k] ret_from_sys_call                
     0.12%     sshd  [kernel.kallsyms]    [k] sysret_signal                    
     0.12%     sshd  [kernel.kallsyms]    [k] local_bh_disable                 
     0.12%     sshd  [kernel.kallsyms]    [k] flush_work                       
     0.12%     sshd  [kernel.kallsyms]    [k] flush_delayed_work               
     0.12%     sshd  [kernel.kallsyms]    [k] schedule_delayed_work            
     0.12%     sshd  [kernel.kallsyms]    [k] remove_wait_queue                
     0.12%     sshd  [kernel.kallsyms]    [k] audit_syscall_entry              
     0.12%     sshd  [kernel.kallsyms]    [k] handle_IRQ_event                 
     0.12%     sshd  [kernel.kallsyms]    [k] rcu_sched_qs                     
     0.12%     sshd  [kernel.kallsyms]    [k] kmem_cache_alloc_node            
     0.12%     sshd  [kernel.kallsyms]    [k] kmem_cache_alloc                 
     0.12%     sshd  [kernel.kallsyms]    [k] kmem_cache_alloc_node_trace      
     0.12%     sshd  [kernel.kallsyms]    [k] do_sync_write                    
     0.12%     sshd  [kernel.kallsyms]    [k] path_put                         
     0.12%     sshd  [kernel.kallsyms]    [k] poll_schedule_timeout            
     0.12%     sshd  [kernel.kallsyms]    [k] free_poll_entry                  
     0.12%     sshd  [kernel.kallsyms]    [k] dput                             
     0.12%     sshd  [kernel.kallsyms]    [k] inotify_dentry_parent_queue_event
     0.12%     sshd  [kernel.kallsyms]    [k] cap_file_permission              
     0.12%     sshd  [kernel.kallsyms]    [k] tty_paranoia_check               
     0.12%     sshd  [kernel.kallsyms]    [k] tty_write                        
     0.12%     sshd  [kernel.kallsyms]    [k] tty_unthrottle                   
     0.12%     sshd  [kernel.kallsyms]    [k] tty_ldisc_ref_wait               
     0.12%     sshd  [kernel.kallsyms]    [k] tty_insert_flip_string           
     0.12%     sshd  [kernel.kallsyms]    [k] sock_aio_read                    
     0.12%     sshd  [kernel.kallsyms]    [k] sock_aio_write                   
     0.12%     sshd  [kernel.kallsyms]    [k] sock_update_classid              
     0.12%     sshd  [kernel.kallsyms]    [k] sock_rfree                       
     0.12%     sshd  [kernel.kallsyms]    [k] release_sock                     
     0.12%     sshd  [kernel.kallsyms]    [k] skb_push                         
     0.12%     sshd  [kernel.kallsyms]    [k] skb_release_data                 
     0.12%     sshd  [kernel.kallsyms]    [k] dev_queue_xmit_nit               
     0.12%     sshd  [kernel.kallsyms]    [k] dev_hard_start_xmit              
     0.12%     sshd  [kernel.kallsyms]    [k] dst_release                      
     0.12%     sshd  [kernel.kallsyms]    [k] ip_queue_xmit                    
     0.12%     sshd  [kernel.kallsyms]    [k] ip_finish_output                 
     0.12%     sshd  [kernel.kallsyms]    [k] tcp_transmit_skb                 
     0.12%     sshd  [kernel.kallsyms]    [k] tcp_v4_rcv                       
     0.12%     sshd  [kernel.kallsyms]    [k] _spin_lock_bh                    


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

@hiboma
Copy link
Author

hiboma commented Mar 30, 2014

sshd + /proc/irq/19/smp_affinity が 8

  • iowrite16 がボトルネックになった
    • IOポートに書く?奴? ここの割合が高いのはいいことな気がする
# ========
# captured on: Sun Mar 30 01:51:34 2014
# hostname : vagrant-centos65.vagrantup.com
# os release : 2.6.32-431.el6.x86_64
# perf version : 2.6.32-431.11.2.el6.x86_64.debug
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i7-4558U CPU @ 2.80GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 603168 kB
# cmdline : /usr/bin/perf record -p 1729 -o 8-sshd.raw 
# event : name = cpu-clock, type = 1, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, id = { 62 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: tracepoint = 2, software = 1
# ========
#
# Samples: 1K of event 'cpu-clock'
# Event count (approx.): 1261
#
# Overhead  Command        Shared Object                           Symbol
# ........  .......  ...................  ...............................
#
    51.39%     sshd  [kernel.kallsyms]    [k] iowrite16                  
     8.96%     sshd  [kernel.kallsyms]    [k] finish_task_switch         
     8.33%     sshd  [kernel.kallsyms]    [k] _spin_unlock_irqrestore    
     4.04%     sshd  sshd                 [.] 0x0000000000042f9c         
     4.04%     sshd  libcrypto.so.1.0.1e  [.] vpaes_encrypt              
     3.49%     sshd  libcrypto.so.1.0.1e  [.] 0x00000000000e3671         
     1.59%     sshd  libz.so.1.2.3        [.] 0x0000000000004ff0         
     1.35%     sshd  [kernel.kallsyms]    [k] __do_softirq               
     0.71%     sshd  [kernel.kallsyms]    [k] do_select                  
     0.56%     sshd  libc-2.12.so         [.] memcpy                     
     0.48%     sshd  libc-2.12.so         [.] __select                   
     0.48%     sshd  [kernel.kallsyms]    [k] core_sys_select            
     0.48%     sshd  [kernel.kallsyms]    [k] copy_user_generic_string   
     0.40%     sshd  libz.so.1.2.3        [.] inflate                    
     0.40%     sshd  libc-2.12.so         [.] sigemptyset                
     0.40%     sshd  [kernel.kallsyms]    [k] pipe_poll                  
     0.32%     sshd  [kernel.kallsyms]    [k] current_fs_time            
     0.32%     sshd  [kernel.kallsyms]    [k] sys_rt_sigprocmask         
     0.32%     sshd  [kernel.kallsyms]    [k] __audit_syscall_exit       
     0.32%     sshd  [kernel.kallsyms]    [k] get_page                   
     0.32%     sshd  [kernel.kallsyms]    [k] sys_read                   
     0.32%     sshd  [kernel.kallsyms]    [k] set_fd_set                 
     0.32%     sshd  [kernel.kallsyms]    [k] tcp_poll                   
     0.24%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Final                 
     0.24%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Init                  
     0.24%     sshd  libcrypto.so.1.0.1e  [.] RAND_get_rand_method       
     0.24%     sshd  libc-2.12.so         [.] __errno_location           
     0.24%     sshd  [kernel.kallsyms]    [k] audit_syscall_entry        
     0.24%     sshd  [kernel.kallsyms]    [k] kfree                      
     0.24%     sshd  [kernel.kallsyms]    [k] n_tty_poll                 
     0.24%     sshd  [kernel.kallsyms]    [k] skb_copy_datagram_iovec    
     0.24%     sshd  [kernel.kallsyms]    [k] tcp_v4_send_check          
     0.24%     sshd  [kernel.kallsyms]    [k] packet_rcv                 
     0.16%     sshd  sshd                 [.] memcpy@plt                 
     0.16%     sshd  libz.so.1.2.3        [.] adler32                    
     0.16%     sshd  libz.so.1.2.3        [.] deflate                    
     0.16%     sshd  libcrypto.so.1.0.1e  [.] RAND_bytes                 
     0.16%     sshd  libcrypto.so.1.0.1e  [.] FIPS_selftest_check        
     0.16%     sshd  libc-2.12.so         [.] __memset_sse2              
     0.16%     sshd  libc-2.12.so         [.] __GI___libc_read           
     0.16%     sshd  [virtio_pci]         [k] vp_notify                  
     0.16%     sshd  [kernel.kallsyms]    [k] system_call                
     0.16%     sshd  [kernel.kallsyms]    [k] sigprocmask                
     0.16%     sshd  [kernel.kallsyms]    [k] flush_work                 
     0.16%     sshd  [kernel.kallsyms]    [k] kmem_cache_free            
     0.16%     sshd  [kernel.kallsyms]    [k] rw_verify_area             
     0.16%     sshd  [kernel.kallsyms]    [k] vfs_read                   
     0.16%     sshd  [kernel.kallsyms]    [k] fget_light                 
     0.16%     sshd  [kernel.kallsyms]    [k] fput                       
     0.16%     sshd  [kernel.kallsyms]    [k] ioread8                    
     0.16%     sshd  [kernel.kallsyms]    [k] pty_write_room             
     0.16%     sshd  [kernel.kallsyms]    [k] sock_update_classid        
     0.16%     sshd  [kernel.kallsyms]    [k] dev_queue_xmit_nit         
     0.16%     sshd  [kernel.kallsyms]    [k] dev_hard_start_xmit        
     0.16%     sshd  [kernel.kallsyms]    [k] dev_queue_xmit             
     0.16%     sshd  [kernel.kallsyms]    [k] tcp_sendmsg                
     0.16%     sshd  [kernel.kallsyms]    [k] tcp_recvmsg                
     0.08%     sshd  sshd                 [.] memset@plt                 
     0.08%     sshd  sshd                 [.] sigemptyset@plt            
     0.08%     sshd  libz.so.1.2.3        [.] _tr_align                  
     0.08%     sshd  libz.so.1.2.3        [.] _tr_flush_block            
     0.08%     sshd  libcrypto.so.1.0.1e  [.] getpid@plt                 
     0.08%     sshd  libcrypto.so.1.0.1e  [.] CRYPTO_lock                
     0.08%     sshd  libcrypto.so.1.0.1e  [.] md5_block_asm_data_order   
     0.08%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Init_ex               
     0.08%     sshd  libcrypto.so.1.0.1e  [.] EVP_MD_CTX_cleanup         
     0.08%     sshd  libcrypto.so.1.0.1e  [.] EVP_EncryptUpdate          
     0.08%     sshd  libcrypto.so.1.0.1e  [.] EVP_MD_CTX_clear_flags     
     0.08%     sshd  libcrypto.so.1.0.1e  [.] EVP_Cipher                 
     0.08%     sshd  libc-2.12.so         [.] sigaddset                  
     0.08%     sshd  libc-2.12.so         [.] _int_malloc                
     0.08%     sshd  libc-2.12.so         [.] getpid                     
     0.08%     sshd  libc-2.12.so         [.] __write_nocancel           
     0.08%     sshd  [virtio_ring]        [k] detach_buf                 
     0.08%     sshd  [virtio_net]         [k] start_xmit                 
     0.08%     sshd  [kernel.kallsyms]    [k] del_timer_sync             
     0.08%     sshd  [kernel.kallsyms]    [k] flush_delayed_work         
     0.08%     sshd  [kernel.kallsyms]    [k] queue_delayed_work_on      
     0.08%     sshd  [kernel.kallsyms]    [k] remove_wait_queue          
     0.08%     sshd  [kernel.kallsyms]    [k] unroll_tree_refs           
     0.08%     sshd  [kernel.kallsyms]    [k] kmem_cache_alloc_node_trace
     0.08%     sshd  [kernel.kallsyms]    [k] path_put                   
     0.08%     sshd  [kernel.kallsyms]    [k] poll_freewait              
     0.08%     sshd  [kernel.kallsyms]    [k] sys_select                 
     0.08%     sshd  [kernel.kallsyms]    [k] inotify_inode_queue_event  
     0.08%     sshd  [kernel.kallsyms]    [k] security_file_permission   
     0.08%     sshd  [kernel.kallsyms]    [k] security_socket_recvmsg    
     0.08%     sshd  [kernel.kallsyms]    [k] tty_paranoia_check         
     0.08%     sshd  [kernel.kallsyms]    [k] tty_poll                   
     0.08%     sshd  [kernel.kallsyms]    [k] tty_write                  
     0.08%     sshd  [kernel.kallsyms]    [k] process_echoes             
     0.08%     sshd  [kernel.kallsyms]    [k] n_tty_write                
     0.08%     sshd  [kernel.kallsyms]    [k] n_tty_read                 
     0.08%     sshd  [kernel.kallsyms]    [k] tty_chars_in_buffer        
     0.08%     sshd  [kernel.kallsyms]    [k] put_ldisc                  
     0.08%     sshd  [kernel.kallsyms]    [k] tty_insert_flip_string     
     0.08%     sshd  [kernel.kallsyms]    [k] pty_chars_in_buffer        
     0.08%     sshd  [kernel.kallsyms]    [k] tty_audit_add_data         
     0.08%     sshd  [kernel.kallsyms]    [k] sock_poll                  
     0.08%     sshd  [kernel.kallsyms]    [k] sock_aio_read              
     0.08%     sshd  [kernel.kallsyms]    [k] sock_update_netprioidx     
     0.08%     sshd  [kernel.kallsyms]    [k] __sk_dst_check             
     0.08%     sshd  [kernel.kallsyms]    [k] __skb_to_sgvec             
     0.08%     sshd  [kernel.kallsyms]    [k] __kfree_skb                
     0.08%     sshd  [kernel.kallsyms]    [k] consume_skb                
     0.08%     sshd  [kernel.kallsyms]    [k] ipv4_dst_check             
     0.08%     sshd  [kernel.kallsyms]    [k] __ip_local_out             
     0.08%     sshd  [kernel.kallsyms]    [k] __inet_lookup_established  
     0.08%     sshd  [kernel.kallsyms]    [k] tcp_push                   
     0.08%     sshd  [kernel.kallsyms]    [k] tcp_rcv_space_adjust       
     0.08%     sshd  [kernel.kallsyms]    [k] tcp_transmit_skb           
     0.08%     sshd  [kernel.kallsyms]    [k] tcp_event_new_data_sent    
     0.08%     sshd  [kernel.kallsyms]    [k] thread_return              
     0.08%     sshd  [kernel.kallsyms]    [k] schedule_hrtimeout_range   


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

@hiboma
Copy link
Author

hiboma commented Mar 30, 2014

bash + /proc/irq/19/smp_affinity が f (デフォルト)

  • acpi_pm_read が重要
    • クロックソースを HPET にすると消える
# ========
# captured on: Sun Mar 30 01:49:31 2014
# hostname : vagrant-centos65.vagrantup.com
# os release : 2.6.32-431.el6.x86_64
# perf version : 2.6.32-431.11.2.el6.x86_64.debug
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i7-4558U CPU @ 2.80GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 603168 kB
# cmdline : /usr/bin/perf record -p 1730 -o f-bash.raw 
# event : name = cpu-clock, type = 1, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, id = { 58 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: tracepoint = 2, software = 1
# ========
#
# Samples: 1K of event 'cpu-clock'
# Event count (approx.): 1713
#
# Overhead  Command      Shared Object                               Symbol
# ........  .......  .................  ...................................
#
    42.91%     bash  [kernel.kallsyms]  [k] acpi_pm_read                   
     8.17%     bash  [kernel.kallsyms]  [k] _spin_unlock_irqrestore        
     7.59%     bash  libc-2.12.so       [.] __strlen_sse2                  
     3.68%     bash  libc-2.12.so       [.] __gconv_transform_utf8_internal
     3.68%     bash  libc-2.12.so       [.] __mbrtowc                      
     3.56%     bash  bash               [.] 0x000000000001f683             
     3.39%     bash  [kernel.kallsyms]  [k] finish_task_switch             
     2.45%     bash  libc-2.12.so       [.] _int_malloc                    
     1.75%     bash  libc-2.12.so       [.] __GI___strcmp_ssse3            
     0.70%     bash  libc-2.12.so       [.] __strcpy_ssse3                 
     0.64%     bash  bash               [.] yyparse                        
     0.58%     bash  libc-2.12.so       [.] _int_free                      
     0.58%     bash  bash               [.] hash_search                    
     0.47%     bash  libc-2.12.so       [.] __strncpy_ssse3                
     0.47%     bash  [kernel.kallsyms]  [k] __audit_syscall_exit           
     0.41%     bash  [kernel.kallsyms]  [k] do_sigaction                   
     0.41%     bash  [kernel.kallsyms]  [k] kmem_cache_alloc               
     0.35%     bash  bash               [.] rl_getc                        
     0.35%     bash  [kernel.kallsyms]  [k] kfree                          
     0.29%     bash  bash               [.] xmalloc                        
     0.29%     bash  bash               [.] mbschr                         
     0.29%     bash  [kernel.kallsyms]  [k] __kmalloc                      
     0.23%     bash  libc-2.12.so       [.] vfprintf                       
     0.23%     bash  libc-2.12.so       [.] malloc_consolidate             
     0.23%     bash  libc-2.12.so       [.] memcpy                         
     0.23%     bash  libc-2.12.so       [.] wcwidth                        
     0.23%     bash  libc-2.12.so       [.] _dl_mcount_wrapper_check       
     0.23%     bash  bash               [.] array_copy                     
     0.23%     bash  [kernel.kallsyms]  [k] __do_softirq                   
     0.23%     bash  [kernel.kallsyms]  [k] sigprocmask                    
     0.23%     bash  [kernel.kallsyms]  [k] audit_syscall_entry            
     0.23%     bash  [kernel.kallsyms]  [k] __call_rcu                     
     0.23%     bash  [kernel.kallsyms]  [k] security_d_instantiate         
     0.23%     bash  [kernel.kallsyms]  [k] netlink_create                 
     0.18%     bash  libc-2.12.so       [.] __ctype_get_mb_cur_max         
     0.18%     bash  libc-2.12.so       [.] free                           
     0.18%     bash  libc-2.12.so       [.] __strchr_sse2                  
     0.18%     bash  libc-2.12.so       [.] __wcslen                       
     0.18%     bash  bash               [.] execute_command_internal       
     0.18%     bash  bash               [.] var_lookup                     
     0.18%     bash  bash               [.] find_variable                  
     0.18%     bash  bash               [.] get_string_value               
     0.18%     bash  bash               [.] rl_expand_prompt               
     0.18%     bash  bash               [.] rl_redisplay                   
     0.18%     bash  bash               [.] _rl_adjust_point               
     0.18%     bash  [kernel.kallsyms]  [k] sysret_signal                  
     0.18%     bash  [kernel.kallsyms]  [k] sys_rt_sigprocmask             
     0.18%     bash  [kernel.kallsyms]  [k] flush_work                     
     0.18%     bash  [kernel.kallsyms]  [k] bit_waitqueue                  
     0.18%     bash  [kernel.kallsyms]  [k] kmem_cache_alloc_node_trace    
     0.18%     bash  [kernel.kallsyms]  [k] vfs_read                       
     0.18%     bash  [kernel.kallsyms]  [k] inotify_inode_queue_event      
     0.18%     bash  [kernel.kallsyms]  [k] copy_user_generic_string       
     0.18%     bash  [kernel.kallsyms]  [k] n_tty_write                    
     0.18%     bash  [kernel.kallsyms]  [k] sk_prot_alloc                  
     0.18%     bash  [kernel.kallsyms]  [k] notifier_call_chain            
     0.12%     bash  libc-2.12.so       [.] __GI___libc_sigaction          
     0.12%     bash  libc-2.12.so       [.] __GI_____strtoll_l_internal    
     0.12%     bash  libc-2.12.so       [.] __fpurge                       
     0.12%     bash  libc-2.12.so       [.] malloc                         
     0.12%     bash  libc-2.12.so       [.] realloc                        
     0.12%     bash  libc-2.12.so       [.] __mempcpy                      
     0.12%     bash  libc-2.12.so       [.] __printf_chk                   
     0.12%     bash  bash               [.] save_parser_state              
     0.12%     bash  bash               [.] assignment                     
     0.12%     bash  bash               [.] find_variable_internal         
     0.12%     bash  bash               [.] get_variable_value             
     0.12%     bash  bash               [.] copy_word_list                 
     0.12%     bash  bash               [.] pat_subst                      
     0.12%     bash  bash               [.] dequote_string                 
     0.12%     bash  bash               [.] list_reverse                   
     0.12%     bash  bash               [.] parse_and_execute              
     0.12%     bash  bash               [.] internal_getopt                
     0.12%     bash  bash               [.] readline_internal_char         
     0.12%     bash  bash               [.] rl_reset_line_state            
     0.12%     bash  bash               [.] _rl_update_final               
     0.12%     bash  bash               [.] rl_newline                     
     0.12%     bash  [kernel.kallsyms]  [k] system_call                    
     0.12%     bash  [kernel.kallsyms]  [k] __rcu_process_callbacks        
     0.12%     bash  [kernel.kallsyms]  [k] rw_verify_area                 
     0.12%     bash  [kernel.kallsyms]  [k] fget_light                     
     0.12%     bash  [kernel.kallsyms]  [k] fput                           
     0.12%     bash  [kernel.kallsyms]  [k] fsnotify                       
     0.12%     bash  [kernel.kallsyms]  [k] inotify_d_instantiate          
     0.12%     bash  [kernel.kallsyms]  [k] locks_remove_posix             
     0.12%     bash  [kernel.kallsyms]  [k] cap_d_instantiate              
     0.12%     bash  [kernel.kallsyms]  [k] ima_inode_alloc                
     0.12%     bash  [kernel.kallsyms]  [k] n_tty_set_termios              
     0.12%     bash  [kernel.kallsyms]  [k] tty_termios_baud_rate          
     0.12%     bash  [kernel.kallsyms]  [k] tty_unthrottle                 
     0.12%     bash  [kernel.kallsyms]  [k] netlink_table_ungrab           
     0.12%     bash  [kernel.kallsyms]  [k] netlink_unicast                
     0.12%     bash  [kernel.kallsyms]  [k] netlink_sendmsg                
     0.12%     bash  [kernel.kallsyms]  [k] mutex_lock                     
     0.06%     bash  libc-2.12.so       [.] __ctype_b_loc                  
     0.06%     bash  libc-2.12.so       [.] __GI___sigaction               
     0.06%     bash  libc-2.12.so       [.] sigemptyset                    
     0.06%     bash  libc-2.12.so       [.] _IO_fflush                     
     0.06%     bash  libc-2.12.so       [.] _IO_fwrite                     
     0.06%     bash  libc-2.12.so       [.] fileno                         
     0.06%     bash  libc-2.12.so       [.] _IO_putc                       
     0.06%     bash  libc-2.12.so       [.] _IO_file_xsputn@@GLIBC_2.2.5   
     0.06%     bash  libc-2.12.so       [.] _IO_file_write@@GLIBC_2.2.5    
     0.06%     bash  libc-2.12.so       [.] __memset_sse2                  
     0.06%     bash  libc-2.12.so       [.] __strchrnul                    
     0.06%     bash  libc-2.12.so       [.] __mbsinit                      
     0.06%     bash  libc-2.12.so       [.] __GI___libc_close              
     0.06%     bash  libc-2.12.so       [.] __GI___libc_sendmsg            
     0.06%     bash  libc-2.12.so       [.] __GI___socket                  
     0.06%     bash  bash               [.] __ctype_get_mb_cur_max@plt     
     0.06%     bash  bash               [.] strchr@plt                     
     0.06%     bash  bash               [.] _IO_putc@plt                   
     0.06%     bash  bash               [.] read_command                   
     0.06%     bash  bash               [.] reader_loop                    
     0.06%     bash  bash               [.] set_current_prompt_level       
     0.06%     bash  bash               [.] with_input_from_string         
     0.06%     bash  bash               [.] decode_prompt_string           
     0.06%     bash  bash               [.] make_word_list                 
     0.06%     bash  bash               [.] alloc_word_desc                
     0.06%     bash  bash               [.] make_word_flags                
     0.06%     bash  bash               [.] make_word                      
     0.06%     bash  bash               [.] new_fd_bitmap                  
     0.06%     bash  bash               [.] bind_variable                  
     0.06%     bash  bash               [.] dispose_used_env_vars          
     0.06%     bash  bash               [.] copy_word                      
     0.06%     bash  bash               [.] quote_escapes                  
     0.06%     bash  bash               [.] remove_quoted_nulls            
     0.06%     bash  bash               [.] dequote_list                   
     0.06%     bash  bash               [.] expand_words                   
     0.06%     bash  bash               [.] signal_is_ignored              
     0.06%     bash  bash               [.] run_pending_traps              
     0.06%     bash  bash               [.] begin_unwind_frame             
     0.06%     bash  bash               [.] unquoted_glob_pattern_p        
     0.06%     bash  bash               [.] valid_array_reference          
     0.06%     bash  bash               [.] xrealloc                       
     0.06%     bash  bash               [.] printf_builtin                 
     0.06%     bash  bash               [.] internal_wstrmatch             
     0.06%     bash  bash               [.] xdupmbstowcs                   
     0.06%     bash  bash               [.] rl_initialize                  
     0.06%     bash  bash               [.] rl_on_new_line                 
     0.06%     bash  bash               [.] _rl_move_vert                  
     0.06%     bash  bash               [.] rl_read_key                    
     0.06%     bash  bash               [.] rl_crlf                        
     0.06%     bash  bash               [.] _rl_set_insert_mode            
     0.06%     bash  [vsyscall]         [.] 0x0000000000000400             
     0.06%     bash  [kernel.kallsyms]  [k] __wake_up                      
     0.06%     bash  [kernel.kallsyms]  [k] timespec_trunc                 
     0.06%     bash  [kernel.kallsyms]  [k] current_fs_time                
     0.06%     bash  [kernel.kallsyms]  [k] sys_gettimeofday               
     0.06%     bash  [kernel.kallsyms]  [k] init_timer_key                 
     0.06%     bash  [kernel.kallsyms]  [k] lock_timer_base                
     0.06%     bash  [kernel.kallsyms]  [k] add_timer                      
     0.06%     bash  [kernel.kallsyms]  [k] sys_rt_sigaction               
     0.06%     bash  [kernel.kallsyms]  [k] find_vpid                      
     0.06%     bash  [kernel.kallsyms]  [k] user_ns_map_gid                
     0.06%     bash  [kernel.kallsyms]  [k] user_ns_map_uid                
     0.06%     bash  [kernel.kallsyms]  [k] unroll_tree_refs               
     0.06%     bash  [kernel.kallsyms]  [k] handle_IRQ_event               
     0.06%     bash  [kernel.kallsyms]  [k] call_rcu_sched                 
     0.06%     bash  [kernel.kallsyms]  [k] kmem_cache_alloc_node          
     0.06%     bash  [kernel.kallsyms]  [k] vfs_write                      
     0.06%     bash  [kernel.kallsyms]  [k] sys_write                      
     0.06%     bash  [kernel.kallsyms]  [k] dentry_iput                    
     0.06%     bash  [kernel.kallsyms]  [k] __d_lookup                     
     0.06%     bash  [kernel.kallsyms]  [k] dput                           
     0.06%     bash  [kernel.kallsyms]  [k] inode_init_always              
     0.06%     bash  [kernel.kallsyms]  [k] alloc_inode                    
     0.06%     bash  [kernel.kallsyms]  [k] cap_netlink_recv               
     0.06%     bash  [kernel.kallsyms]  [k] security_netlink_send          
     0.06%     bash  [kernel.kallsyms]  [k] cap_inode_alloc_security       
     0.06%     bash  [kernel.kallsyms]  [k] cap_socket_create              
     0.06%     bash  [kernel.kallsyms]  [k] ima_file_free                  
     0.06%     bash  [kernel.kallsyms]  [k] _atomic_dec_and_lock           
     0.06%     bash  [kernel.kallsyms]  [k] copy_from_user                 
     0.06%     bash  [kernel.kallsyms]  [k] tty_paranoia_check             
     0.06%     bash  [kernel.kallsyms]  [k] tty_ioctl                      
     0.06%     bash  [kernel.kallsyms]  [k] process_echoes                 
     0.06%     bash  [kernel.kallsyms]  [k] n_tty_ioctl                    
     0.06%     bash  [kernel.kallsyms]  [k] n_tty_read                     
     0.06%     bash  [kernel.kallsyms]  [k] tty_write_room                 
     0.06%     bash  [kernel.kallsyms]  [k] set_termios                    
     0.06%     bash  [kernel.kallsyms]  [k] n_tty_ioctl_helper             
     0.06%     bash  [kernel.kallsyms]  [k] put_ldisc                      
     0.06%     bash  [kernel.kallsyms]  [k] tty_ldisc_ref_wait             
     0.06%     bash  [kernel.kallsyms]  [k] scsi_nl_rcv_event              
     0.06%     bash  [kernel.kallsyms]  [k] sock_alloc                     
     0.06%     bash  [kernel.kallsyms]  [k] sock_create                    
     0.06%     bash  [kernel.kallsyms]  [k] move_addr_to_kernel            
     0.06%     bash  [kernel.kallsyms]  [k] sys_sendmsg                    
     0.06%     bash  [kernel.kallsyms]  [k] skb_release_head_state         
     0.06%     bash  [kernel.kallsyms]  [k] netlink_table_grab             
     0.06%     bash  [kernel.kallsyms]  [k] netlink_sendskb                
     0.06%     bash  [kernel.kallsyms]  [k] mutex_lock_interruptible       
     0.06%     bash  [kernel.kallsyms]  [k] _read_lock                     
     0.06%     bash  [kernel.kallsyms]  [k] _spin_lock_irqsave             


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

@hiboma
Copy link
Author

hiboma commented Mar 30, 2014

bash + /proc/irq/19/smp_affinity が 8

  • acpi_pm_read が重要
  • smp_affinity がデフォルトの時と差がなさそう
# ========
# captured on: Sun Mar 30 01:50:53 2014
# hostname : vagrant-centos65.vagrantup.com
# os release : 2.6.32-431.el6.x86_64
# perf version : 2.6.32-431.11.2.el6.x86_64.debug
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i7-4558U CPU @ 2.80GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 603168 kB
# cmdline : /usr/bin/perf record -p 1730 -o 8-bash.raw 
# event : name = cpu-clock, type = 1, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, id = { 60 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: tracepoint = 2, software = 1
# ========
#
# Samples: 1K of event 'cpu-clock'
# Event count (approx.): 1954
#
# Overhead  Command      Shared Object                                    Symbol
# ........  .......  .................  ........................................
#
    46.98%     bash  [kernel.kallsyms]  [k] acpi_pm_read                        
    11.41%     bash  libc-2.12.so       [.] __strlen_sse2                       
     2.97%     bash  libc-2.12.so       [.] __mbrtowc                           
     2.81%     bash  libc-2.12.so       [.] __GI___strcmp_ssse3                 
     2.76%     bash  libc-2.12.so       [.] __gconv_transform_utf8_internal     
     2.56%     bash  bash               [.] 0x000000000002eadb                  
     2.30%     bash  [kernel.kallsyms]  [k] _spin_unlock_irqrestore             
     2.00%     bash  [kernel.kallsyms]  [k] finish_task_switch                  
     1.23%     bash  libc-2.12.so       [.] _int_malloc                         
     1.23%     bash  libc-2.12.so       [.] __strcpy_ssse3                      
     0.97%     bash  libc-2.12.so       [.] _int_free                           
     0.82%     bash  libc-2.12.so       [.] __strchr_sse2                       
     0.61%     bash  libc-2.12.so       [.] __strncpy_ssse3                     
     0.46%     bash  bash               [.] yyparse                             
     0.41%     bash  libc-2.12.so       [.] __ctype_get_mb_cur_max              
     0.41%     bash  libc-2.12.so       [.] malloc                              
     0.36%     bash  bash               [.] rl_redisplay                        
     0.36%     bash  [kernel.kallsyms]  [k] __audit_syscall_exit                
     0.36%     bash  [kernel.kallsyms]  [k] copy_user_generic_string            
     0.31%     bash  libc-2.12.so       [.] free                                
     0.31%     bash  libc-2.12.so       [.] __strchrnul                         
     0.31%     bash  [kernel.kallsyms]  [k] system_call                         
     0.31%     bash  [kernel.kallsyms]  [k] n_tty_write                         
     0.26%     bash  libc-2.12.so       [.] __memset_sse2                       
     0.26%     bash  bash               [.] find_variable                       
     0.26%     bash  bash               [.] hash_search                         
     0.26%     bash  bash               [.] printf_builtin                      
     0.26%     bash  bash               [.] mbschr                              
     0.26%     bash  [kernel.kallsyms]  [k] flush_work                          
     0.26%     bash  [kernel.kallsyms]  [k] bit_waitqueue                       
     0.26%     bash  [kernel.kallsyms]  [k] unroll_tree_refs                    
     0.26%     bash  [kernel.kallsyms]  [k] audit_syscall_entry                 
     0.26%     bash  [kernel.kallsyms]  [k] __alloc_skb                         
     0.26%     bash  [kernel.kallsyms]  [k] netlink_unicast                     
     0.20%     bash  libc-2.12.so       [.] __gconv_transform_internal_utf8     
     0.20%     bash  libc-2.12.so       [.] _IO_putc                            
     0.20%     bash  libc-2.12.so       [.] memcpy                              
     0.20%     bash  libc-2.12.so       [.] _dl_mcount_wrapper_check            
     0.20%     bash  bash               [.] rl_prep_terminal                    
     0.20%     bash  bash               [.] rl_on_new_line                      
     0.20%     bash  bash               [.] rl_getc                             
     0.20%     bash  [kernel.kallsyms]  [k] sysret_audit                        
     0.20%     bash  [kernel.kallsyms]  [k] __do_softirq                        
     0.20%     bash  [kernel.kallsyms]  [k] do_sigaction                        
     0.20%     bash  [kernel.kallsyms]  [k] find_pid_ns                         
     0.20%     bash  [kernel.kallsyms]  [k] kmem_cache_free                     
     0.20%     bash  [kernel.kallsyms]  [k] fget_light                          
     0.20%     bash  [kernel.kallsyms]  [k] netlink_sendmsg                     
     0.15%     bash  libc-2.12.so       [.] vfprintf                            
     0.15%     bash  libc-2.12.so       [.] _IO_file_write@@GLIBC_2.2.5         
     0.15%     bash  libc-2.12.so       [.] wcwidth                             
     0.15%     bash  bash               [.] mbrtowc@plt                         
     0.15%     bash  bash               [.] make_word_list                      
     0.15%     bash  bash               [.] alloc_word_desc                     
     0.15%     bash  bash               [.] dequote_list                        
     0.15%     bash  bash               [.] xmalloc                             
     0.15%     bash  bash               [.] xdupmbstowcs                        
     0.15%     bash  bash               [.] rl_clear_signals                    
     0.15%     bash  bash               [.] _rl_find_next_mbchar                
     0.15%     bash  [kernel.kallsyms]  [k] queue_delayed_work_on               
     0.15%     bash  [kernel.kallsyms]  [k] kmem_cache_alloc_node               
     0.15%     bash  [kernel.kallsyms]  [k] kmem_cache_alloc                    
     0.15%     bash  [kernel.kallsyms]  [k] kfree                               
     0.15%     bash  [kernel.kallsyms]  [k] tty_read                            
     0.15%     bash  [kernel.kallsyms]  [k] tty_ldisc_deref                     
     0.10%     bash  libc-2.12.so       [.] sigemptyset                         
     0.10%     bash  libc-2.12.so       [.] __strtoll_internal                  
     0.10%     bash  libc-2.12.so       [.] _IO_file_overflow@@GLIBC_2.2.5      
     0.10%     bash  libc-2.12.so       [.] _IO_do_write@@GLIBC_2.2.5           
     0.10%     bash  libc-2.12.so       [.] malloc_consolidate                  
     0.10%     bash  libc-2.12.so       [.] tcsetattr                           
     0.10%     bash  bash               [.] assignment                          
     0.10%     bash  bash               [.] dispose_word                        
     0.10%     bash  bash               [.] dispose_words                       
     0.10%     bash  bash               [.] execute_command_internal            
     0.10%     bash  bash               [.] array_copy                          
     0.10%     bash  bash               [.] array_dispose                       
     0.10%     bash  bash               [.] valid_array_reference               
     0.10%     bash  bash               [.] _rl_update_final                    
     0.10%     bash  bash               [.] rl_read_key                         
     0.10%     bash  bash               [.] _rl_adjust_point                    
     0.10%     bash  [vsyscall]         [.] 0x0000000000000400                  
     0.10%     bash  [kernel.kallsyms]  [k] current_fs_time                     
     0.10%     bash  [kernel.kallsyms]  [k] sys_gettimeofday                    
     0.10%     bash  [kernel.kallsyms]  [k] del_timer_sync                      
     0.10%     bash  [kernel.kallsyms]  [k] sys_rt_sigaction                    
     0.10%     bash  [kernel.kallsyms]  [k] sigprocmask                         
     0.10%     bash  [kernel.kallsyms]  [k] vfs_write                           
     0.10%     bash  [kernel.kallsyms]  [k] dput                                
     0.10%     bash  [kernel.kallsyms]  [k] alloc_fd                            
     0.10%     bash  [kernel.kallsyms]  [k] inotify_inode_queue_event           
     0.10%     bash  [kernel.kallsyms]  [k] ima_inode_alloc                     
     0.10%     bash  [kernel.kallsyms]  [k] tty_ioctl                           
     0.10%     bash  [kernel.kallsyms]  [k] n_tty_set_termios                   
     0.10%     bash  [kernel.kallsyms]  [k] put_ldisc                           
     0.10%     bash  [kernel.kallsyms]  [k] sock_create                         
     0.10%     bash  [kernel.kallsyms]  [k] sk_filter                           
     0.10%     bash  [kernel.kallsyms]  [k] netlink_table_ungrab                
     0.10%     bash  [kernel.kallsyms]  [k] _cond_resched                       
     0.10%     bash  [kernel.kallsyms]  [k] mutex_unlock                        
     0.05%     bash  libc-2.12.so       [.] __errno_location                    
     0.05%     bash  libc-2.12.so       [.] __GI___libc_sigaction               
     0.05%     bash  libc-2.12.so       [.] __sigprocmask                       
     0.05%     bash  libc-2.12.so       [.] __GI_____strtoll_l_internal         
     0.05%     bash  libc-2.12.so       [.] _IO_fflush                          
     0.05%     bash  libc-2.12.so       [.] clearerr                            
     0.05%     bash  libc-2.12.so       [.] _IO_ferror                          
     0.05%     bash  libc-2.12.so       [.] fileno                              
     0.05%     bash  libc-2.12.so       [.] _IO_file_sync@@GLIBC_2.2.5          
     0.05%     bash  libc-2.12.so       [.] realloc                             
     0.05%     bash  libc-2.12.so       [.] __strrchr_sse2                      
     0.05%     bash  libc-2.12.so       [.] __mempcpy                           
     0.05%     bash  libc-2.12.so       [.] __GI___libc_close                   
     0.05%     bash  libc-2.12.so       [.] __GI___libc_read                    
     0.05%     bash  libc-2.12.so       [.] __GI___libc_write                   
     0.05%     bash  libc-2.12.so       [.] __GI___libc_sendmsg                 
     0.05%     bash  libc-2.12.so       [.] __printf_chk                        
     0.05%     bash  bash               [.] malloc@plt                          
     0.05%     bash  bash               [.] strlen@plt                          
     0.05%     bash  bash               [.] read_command                        
     0.05%     bash  bash               [.] reader_loop                         
     0.05%     bash  bash               [.] decode_prompt_string                
     0.05%     bash  bash               [.] make_word_flags                     
     0.05%     bash  bash               [.] dispose_word_desc                   
     0.05%     bash  bash               [.] new_fd_bitmap                       
     0.05%     bash  bash               [.] var_lookup                          
     0.05%     bash  bash               [.] find_variable_internal              
     0.05%     bash  bash               [.] bind_variable                       
     0.05%     bash  bash               [.] get_string_value                    
     0.05%     bash  bash               [.] copy_word                           
     0.05%     bash  bash               [.] copy_word_list                      
     0.05%     bash  bash               [.] pat_subst                           
     0.05%     bash  bash               [.] dequote_string                      
     0.05%     bash  bash               [.] add_unwind_protect                  
     0.05%     bash  bash               [.] unwind_protect_mem                  
     0.05%     bash  bash               [.] quote_string_for_globbing           
     0.05%     bash  bash               [.] set_signal_handler                  
     0.05%     bash  bash               [.] find_alias                          
     0.05%     bash  bash               [.] array_dispose_element               
     0.05%     bash  bash               [.] array_flush                         
     0.05%     bash  bash               [.] substring                           
     0.05%     bash  bash               [.] xrealloc                            
     0.05%     bash  bash               [.] builtin_address_internal            
     0.05%     bash  bash               [.] strvec_dispose                      
     0.05%     bash  bash               [.] sh_backslash_quote_for_double_quotes
     0.05%     bash  bash               [.] _rl_dispatch_subseq                 
     0.05%     bash  bash               [.] readline_internal_setup             
     0.05%     bash  bash               [.] rl_set_prompt                       
     0.05%     bash  bash               [.] readline                            
     0.05%     bash  bash               [.] _rl_block_sigint                    
     0.05%     bash  bash               [.] _rl_reset_argument                  
     0.05%     bash  bash               [.] _rl_set_insert_mode                 
     0.05%     bash  bash               [.] using_history                       
     0.05%     bash  [kernel.kallsyms]  [k] session_of_pgrp                     
     0.05%     bash  [kernel.kallsyms]  [k] local_bh_enable_ip                  
     0.05%     bash  [kernel.kallsyms]  [k] local_bh_enable                     
     0.05%     bash  [kernel.kallsyms]  [k] add_timer                           
     0.05%     bash  [kernel.kallsyms]  [k] sys_rt_sigprocmask                  
     0.05%     bash  [kernel.kallsyms]  [k] schedule_delayed_work               
     0.05%     bash  [kernel.kallsyms]  [k] find_vpid                           
     0.05%     bash  [kernel.kallsyms]  [k] remove_wait_queue                   
     0.05%     bash  [kernel.kallsyms]  [k] hrtimer_peek_ahead_timers           
     0.05%     bash  [kernel.kallsyms]  [k] getnstimeofday                      
     0.05%     bash  [kernel.kallsyms]  [k] current_kernel_time                 
     0.05%     bash  [kernel.kallsyms]  [k] user_ns_map_gid                     
     0.05%     bash  [kernel.kallsyms]  [k] user_ns_map_uid                     
     0.05%     bash  [kernel.kallsyms]  [k] rcu_sched_qs                        
     0.05%     bash  [kernel.kallsyms]  [k] __call_rcu                          
     0.05%     bash  [kernel.kallsyms]  [k] __rcu_process_callbacks             
     0.05%     bash  [kernel.kallsyms]  [k] __kmalloc                           
     0.05%     bash  [kernel.kallsyms]  [k] kmem_cache_alloc_node_trace         
     0.05%     bash  [kernel.kallsyms]  [k] fd_install                          
     0.05%     bash  [kernel.kallsyms]  [k] vfs_read                            
     0.05%     bash  [kernel.kallsyms]  [k] sys_write                           
     0.05%     bash  [kernel.kallsyms]  [k] get_empty_filp                      
     0.05%     bash  [kernel.kallsyms]  [k] path_put                            
     0.05%     bash  [kernel.kallsyms]  [k] vfs_ioctl                           
     0.05%     bash  [kernel.kallsyms]  [k] do_vfs_ioctl                        
     0.05%     bash  [kernel.kallsyms]  [k] sys_ioctl                           
     0.05%     bash  [kernel.kallsyms]  [k] iput                                
     0.05%     bash  [kernel.kallsyms]  [k] generic_detach_inode                
     0.05%     bash  [kernel.kallsyms]  [k] fsnotify                            
     0.05%     bash  [kernel.kallsyms]  [k] __fsnotify_parent                   
     0.05%     bash  [kernel.kallsyms]  [k] fsnotify_clear_marks_by_inode       
     0.05%     bash  [kernel.kallsyms]  [k] security_d_instantiate              
     0.05%     bash  [kernel.kallsyms]  [k] security_inode_alloc                
     0.05%     bash  [kernel.kallsyms]  [k] cap_socket_create                   
     0.05%     bash  [kernel.kallsyms]  [k] cap_d_instantiate                   
     0.05%     bash  [kernel.kallsyms]  [k] ima_file_free                       
     0.05%     bash  [kernel.kallsyms]  [k] ima_counts_get                      
     0.05%     bash  [kernel.kallsyms]  [k] find_next_zero_bit                  
     0.05%     bash  [kernel.kallsyms]  [k] copy_to_user                        
     0.05%     bash  [kernel.kallsyms]  [k] copy_from_user                      
     0.05%     bash  [kernel.kallsyms]  [k] tty_write                           
     0.05%     bash  [kernel.kallsyms]  [k] tty_check_change                    
     0.05%     bash  [kernel.kallsyms]  [k] do_output_char                      
     0.05%     bash  [kernel.kallsyms]  [k] copy_from_read_buf                  
     0.05%     bash  [kernel.kallsyms]  [k] n_tty_read                          
     0.05%     bash  [kernel.kallsyms]  [k] tty_unthrottle                      
     0.05%     bash  [kernel.kallsyms]  [k] set_termios                         
     0.05%     bash  [kernel.kallsyms]  [k] tty_mode_ioctl                      
     0.05%     bash  [kernel.kallsyms]  [k] __sock_create                       
     0.05%     bash  [kernel.kallsyms]  [k] sock_init_data                      
     0.05%     bash  [kernel.kallsyms]  [k] sock_def_readable                   
     0.05%     bash  [kernel.kallsyms]  [k] sk_prot_alloc                       
     0.05%     bash  [kernel.kallsyms]  [k] sk_alloc                            
     0.05%     bash  [kernel.kallsyms]  [k] __sk_free                           
     0.05%     bash  [kernel.kallsyms]  [k] netlink_attachskb                   
     0.05%     bash  [kernel.kallsyms]  [k] schedule                            
     0.05%     bash  [kernel.kallsyms]  [k] wait_for_common                     
     0.05%     bash  [kernel.kallsyms]  [k] schedule_timeout                    
     0.05%     bash  [kernel.kallsyms]  [k] _spin_lock_irqsave                  
     0.05%     bash  [kernel.kallsyms]  [k] _spin_lock                          
     0.05%     bash  [kernel.kallsyms]  [k] _write_unlock_bh                    
     0.05%     bash  [kernel.kallsyms]  [k] atomic_notifier_call_chain          


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

@hiboma
Copy link
Author

hiboma commented Mar 30, 2014

HPET on + sshd + /proc/irq/19/smp_affinity が (f) デフォルト

  • _spin_unlock_irqrestore が下がってるのかな ?
# ========
# captured on: Sun Mar 30 03:03:08 2014
# hostname : vagrant-centos65.vagrantup.com
# os release : 2.6.32-431.el6.x86_64
# perf version : 2.6.32-431.11.2.el6.x86_64.debug
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i7-4558U CPU @ 2.80GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 603168 kB
# cmdline : /usr/bin/perf record -p 1577 
# event : name = cpu-clock, type = 1, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, id = { 30 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: tracepoint = 2, software = 1
# ========
#
# Samples: 382  of event 'cpu-clock'
# Event count (approx.): 382
#
# Overhead  Command        Shared Object                           Symbol
# ........  .......  ...................  ...............................
#
    22.25%     sshd  [kernel.kallsyms]    [k] finish_task_switch         
     9.42%     sshd  sshd                 [.] 0x00000000000160cf         
     7.59%     sshd  [kernel.kallsyms]    [k] iowrite16                  
     7.33%     sshd  libcrypto.so.1.0.1e  [.] vpaes_encrypt              
     6.28%     sshd  libcrypto.so.1.0.1e  [.] 0x00000000000e3671         
     2.88%     sshd  libz.so.1.2.3        [.] 0x00000000000071be         
     2.36%     sshd  [kernel.kallsyms]    [k] _spin_unlock_irqrestore    
     1.83%     sshd  [kernel.kallsyms]    [k] __do_softirq               
     1.57%     sshd  [kernel.kallsyms]    [k] handle_IRQ_event           
     1.31%     sshd  libz.so.1.2.3        [.] inflate                    
     1.31%     sshd  [kernel.kallsyms]    [k] kfree                      
     1.05%     sshd  libcrypto.so.1.0.1e  [.] EVP_Cipher                 
     1.05%     sshd  libc-2.12.so         [.] memcpy                     
     1.05%     sshd  libc-2.12.so         [.] __GI___libc_read           
     1.05%     sshd  [kernel.kallsyms]    [k] __audit_syscall_exit       
     1.05%     sshd  [kernel.kallsyms]    [k] do_select                  
     1.05%     sshd  [kernel.kallsyms]    [k] copy_user_generic_string   
     1.05%     sshd  [kernel.kallsyms]    [k] n_tty_poll                 
     1.05%     sshd  [kernel.kallsyms]    [k] sock_poll                  
     0.79%     sshd  libcrypto.so.1.0.1e  [.] EVP_EncryptUpdate          
     0.79%     sshd  libc-2.12.so         [.] __memset_sse2              
     0.79%     sshd  [kernel.kallsyms]    [k] sigprocmask                
     0.79%     sshd  [kernel.kallsyms]    [k] pipe_poll                  
     0.52%     sshd  libcrypto.so.1.0.1e  [.] FIPS_selftest_check        
     0.52%     sshd  libc-2.12.so         [.] sigemptyset                
     0.52%     sshd  libc-2.12.so         [.] malloc                     
     0.52%     sshd  [virtio_pci]         [k] vp_notify                  
     0.52%     sshd  [kernel.kallsyms]    [k] mod_timer                  
     0.52%     sshd  [kernel.kallsyms]    [k] add_wait_queue             
     0.52%     sshd  [kernel.kallsyms]    [k] current_kernel_time        
     0.52%     sshd  [kernel.kallsyms]    [k] audit_syscall_entry        
     0.52%     sshd  [kernel.kallsyms]    [k] do_sync_read               
     0.52%     sshd  [kernel.kallsyms]    [k] poll_select_copy_remaining 
     0.52%     sshd  [kernel.kallsyms]    [k] copy_from_user             
     0.52%     sshd  [kernel.kallsyms]    [k] n_tty_read                 
     0.52%     sshd  [kernel.kallsyms]    [k] tty_chars_in_buffer        
     0.52%     sshd  [kernel.kallsyms]    [k] tty_audit_add_data         
     0.52%     sshd  [kernel.kallsyms]    [k] skb_copy_datagram_iovec    
     0.52%     sshd  [kernel.kallsyms]    [k] ip_finish_output           
     0.52%     sshd  [kernel.kallsyms]    [k] tcp_poll                   
     0.52%     sshd  [kernel.kallsyms]    [k] schedule_hrtimeout_range   
     0.52%     sshd  [kernel.kallsyms]    [k] _spin_lock_irqsave         
     0.26%     sshd  sshd                 [.] __errno_location@plt       
     0.26%     sshd  sshd                 [.] memset@plt                 
     0.26%     sshd  sshd                 [.] read@plt                   
     0.26%     sshd  sshd                 [.] memcpy@plt                 
     0.26%     sshd  libz.so.1.2.3        [.] adler32                    
     0.26%     sshd  libz.so.1.2.3        [.] _tr_align                  
     0.26%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Update                
     0.26%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Init_ex               
     0.26%     sshd  libcrypto.so.1.0.1e  [.] HMAC_Init                  
     0.26%     sshd  libcrypto.so.1.0.1e  [.] EVP_MD_CTX_copy_ex         
     0.26%     sshd  libc-2.12.so         [.] __errno_location           
     0.26%     sshd  libc-2.12.so         [.] __GI___libc_write          
     0.26%     sshd  libc-2.12.so         [.] __select                   
     0.26%     sshd  [virtio_ring]        [k] virtqueue_add_buf          
     0.26%     sshd  [kernel.kallsyms]    [k] system_call                
     0.26%     sshd  [kernel.kallsyms]    [k] sys_rt_sigprocmask         
     0.26%     sshd  [kernel.kallsyms]    [k] flush_work                 
     0.26%     sshd  [kernel.kallsyms]    [k] rcu_sched_qs               
     0.26%     sshd  [kernel.kallsyms]    [k] put_page                   
     0.26%     sshd  [kernel.kallsyms]    [k] kmem_cache_alloc_node_trace
     0.26%     sshd  [kernel.kallsyms]    [k] do_sync_write              
     0.26%     sshd  [kernel.kallsyms]    [k] vfs_write                  
     0.26%     sshd  [kernel.kallsyms]    [k] vfs_read                   
     0.26%     sshd  [kernel.kallsyms]    [k] fput                       
     0.26%     sshd  [kernel.kallsyms]    [k] path_put                   
     0.26%     sshd  [kernel.kallsyms]    [k] free_poll_entry            
     0.26%     sshd  [kernel.kallsyms]    [k] core_sys_select            
     0.26%     sshd  [kernel.kallsyms]    [k] fsnotify                   
     0.26%     sshd  [kernel.kallsyms]    [k] inotify_inode_queue_event  
     0.26%     sshd  [kernel.kallsyms]    [k] tty_paranoia_check         
     0.26%     sshd  [kernel.kallsyms]    [k] tty_poll                   
     0.26%     sshd  [kernel.kallsyms]    [k] n_tty_write                
     0.26%     sshd  [kernel.kallsyms]    [k] pty_write_room             
     0.26%     sshd  [kernel.kallsyms]    [k] sock_aio_write             
     0.26%     sshd  [kernel.kallsyms]    [k] sock_update_classid        
     0.26%     sshd  [kernel.kallsyms]    [k] lock_sock_nested           
     0.26%     sshd  [kernel.kallsyms]    [k] __skb_to_sgvec             
     0.26%     sshd  [kernel.kallsyms]    [k] __kfree_skb                
     0.26%     sshd  [kernel.kallsyms]    [k] memcpy_toiovec             
     0.26%     sshd  [kernel.kallsyms]    [k] dev_hard_start_xmit        
     0.26%     sshd  [kernel.kallsyms]    [k] dev_queue_xmit             
     0.26%     sshd  [kernel.kallsyms]    [k] dst_release                
     0.26%     sshd  [kernel.kallsyms]    [k] sk_run_filter              
     0.26%     sshd  [kernel.kallsyms]    [k] ip_queue_xmit              
     0.26%     sshd  [kernel.kallsyms]    [k] ip_output                  
     0.26%     sshd  [kernel.kallsyms]    [k] tcp_recvmsg                
     0.26%     sshd  [kernel.kallsyms]    [k] tcp_transmit_skb           
     0.26%     sshd  [kernel.kallsyms]    [k] tcp_event_new_data_sent    
     0.26%     sshd  [kernel.kallsyms]    [k] tcp_write_xmit             
     0.26%     sshd  [kernel.kallsyms]    [k] inet_recvmsg               
     0.26%     sshd  [kernel.kallsyms]    [k] _cond_resched              
     0.26%     sshd  [kernel.kallsyms]    [k] mutex_unlock               
     0.26%     sshd  [kernel.kallsyms]    [k] mutex_trylock              
     0.26%     sshd  [kernel.kallsyms]    [k] _spin_lock                 
     0.26%     sshd  [kernel.kallsyms]    [k] _spin_lock_bh              


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

@hiboma
Copy link
Author

hiboma commented Mar 30, 2014

HPET on + bash + /proc/irq/19/smp_affinity が (f) デフォルト

  • acpi_pm_read が消えた !!!
# ========
# captured on: Sun Mar 30 03:07:25 2014
# hostname : vagrant-centos65.vagrantup.com
# os release : 2.6.32-431.el6.x86_64
# perf version : 2.6.32-431.11.2.el6.x86_64.debug
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i7-4558U CPU @ 2.80GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 603168 kB
# cmdline : /usr/bin/perf record -p 1578 
# event : name = cpu-clock, type = 1, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, id = { 32 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: tracepoint = 2, software = 1
# ========
#
# Samples: 36  of event 'cpu-clock'
# Event count (approx.): 36
#
# Overhead  Command      Shared Object                               Symbol
# ........  .......  .................  ...................................
#
    16.67%     bash  libc-2.12.so       [.] __strlen_sse2                  
    16.67%     bash  bash               [.] 0x000000000004b57e             
     8.33%     bash  libc-2.12.so       [.] __GI___strcmp_ssse3            
     5.56%     bash  libc-2.12.so       [.] __gconv_transform_utf8_internal
     5.56%     bash  libc-2.12.so       [.] __mbrtowc                      
     2.78%     bash  libc-2.12.so       [.] malloc                         
     2.78%     bash  libc-2.12.so       [.] __wcslen                       
     2.78%     bash  libc-2.12.so       [.] _dl_mcount_wrapper_check       
     2.78%     bash  bash               [.] yyparse                        
     2.78%     bash  bash               [.] dispose_fd_bitmap              
     2.78%     bash  bash               [.] hash_search                    
     2.78%     bash  bash               [.] rl_prep_terminal               
     2.78%     bash  bash               [.] _rl_start_using_history        
     2.78%     bash  bash               [.] _rl_adjust_point               
     2.78%     bash  [kernel.kallsyms]  [k] finish_task_switch             
     2.78%     bash  [kernel.kallsyms]  [k] bit_waitqueue                  
     2.78%     bash  [kernel.kallsyms]  [k] kmem_cache_alloc_node_trace    
     2.78%     bash  [kernel.kallsyms]  [k] kfree                          
     2.78%     bash  [kernel.kallsyms]  [k] vfs_ioctl                      
     2.78%     bash  [kernel.kallsyms]  [k] inotify_inode_queue_event      
     2.78%     bash  [kernel.kallsyms]  [k] tty_flip_buffer_push           
     2.78%     bash  [kernel.kallsyms]  [k] netlink_table_ungrab           


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment