Re: [lwip-users] TCP bandwidth limited by rate of ACKs

[Bill Auerbach]

That 7.4% for memcpy is a direct hit on throughput.  You're seeing a
breakdown of total CPU time.  How much of that 7+% for memcpy comes out of
the total time used by lwIP?  I think you'll find that to be a much larger
hit and a large contributor to lower bandwidth.

>OS21 profile analysis for main.out
>(16 bytes per bucket, sampled at 1000 Hz, system wide profile)
>
> 515.859 seconds (100.00%) :  Total duration
>
>Task breakdown:
> 218.810 seconds ( 42.42%) :  tcpip_thread
> 144.978 seconds ( 28.10%) :  rxapp
> 121.828 seconds ( 23.62%) :  RxTask
>   0.476 seconds (  0.09%) :  Idle Task
>   0.350 seconds (  0.07%) :  STLAYER-GFX/CUR
>   0.120 seconds (  0.02%) :  STLAYER-GFX/CUR
>   0.092 seconds (  0.02%) :  STDVM_ServiceTa
>   0.071 seconds (  0.01%) :  STLAYER-GFX/CUR
>   0.041 seconds (  0.01%) :  phy: link
>
>Interrupt level breakdown:
>  27.996 seconds (  5.43%) :  Interrupt level 8
>   0.968 seconds (  0.19%) :  Interrupt level 13
>   0.085 seconds (  0.02%) :  Interrupt level 15
>
>Symbolic breakdown:
> 261.467 seconds ( 50.69%) :  _md_kernel_intr_mask
>  38.134 seconds (  7.39%) :  memcpy
>  14.321 seconds (  2.78%) :  stxmac_dma_isr
>  13.661 seconds (  2.65%) :  tcp_input
>   9.797 seconds (  1.90%) :  _md_timer_system_time
>   7.401 seconds (  1.43%) :  _st40_kernel_interrupt_handler600
>   7.133 seconds (  1.38%) :  tcp_receive
>   6.450 seconds (  1.25%) :  _malloc_r
>   5.746 seconds (  1.11%) :  lwip_recvfrom
>   5.469 seconds (  1.06%) :  stxmac_dma_rx_start
>   4.537 seconds (  0.88%) :  _free_r
>   4.333 seconds (  0.84%) :  mutex_release
>   4.216 seconds (  0.82%) :  event_callback
>   4.189 seconds (  0.81%) :  ip_input
>   3.878 seconds (  0.75%) :  stxmac_dma_tx_start
>   3.572 seconds (  0.69%) :  _md_kernel_intr_mask_all
>   3.331 seconds (  0.65%) :  mutex_lock
>   3.315 seconds (  0.64%) :  __divdi3
>   3.016 seconds (  0.58%) :  device_ioctl
>   2.950 seconds (  0.57%) :  _os21_scheduler_lock
>   2.887 seconds (  0.56%) :  ip_output_if
>   2.830 seconds (  0.55%) :  _message_q_remove
>   2.806 seconds (  0.54%) :  __udiv_qrnnd_16
>   2.799 seconds (  0.54%) :  pbuf_alloc
>   2.746 seconds (  0.53%) :  sys_timeouts_mbox_fetch
>   2.701 seconds (  0.52%) :  semaphore_wait
>   2.700 seconds (  0.52%) :  interrupt_unmask
>   2.685 seconds (  0.52%) :  semaphore_wait_timeout
>   2.628 seconds (  0.51%) :  __libc_lock_init_complete_recursive
>   2.514 seconds (  0.49%) :  sys_arch_mbox_fetch
>   2.373 seconds (  0.46%) :  osplus_physical_address
>   2.308 seconds (  0.45%) :  pbuf_header
>   2.190 seconds (  0.42%) :  _message_q_add
>   2.137 seconds (  0.41%) :  _os21_task_is_valid
>   2.121 seconds (  0.41%) :  ethernet_input
>   2.101 seconds (  0.41%) :  recv_tcp
>   1.838 seconds (  0.36%) :  ethernet_api_ioctl
>   1.746 seconds (  0.34%) :  _os21_interrupt_handler
>   1.697 seconds (  0.33%) :  cache_purge_data
>   1.688 seconds (  0.33%) :  lwip_standard_chksum
>   1.654 seconds (  0.32%) :  _st40_cache_purge_data_work_1
>   1.582 seconds (  0.31%) :  __malloc_lock
>   1.551 seconds (  0.30%) :  profile_start_all
>   1.549 seconds (  0.30%) :  pbuf_copy_partial
>   1.485 seconds (  0.29%) :  __malloc_unlock
>   1.479 seconds (  0.29%) :  tcp_output
>   1.450 seconds (  0.28%) :  message_receive_timeout
>   1.444 seconds (  0.28%) :  ip4_addr_isbroadcast
>   1.414 seconds (  0.27%) :  ethernet_ops_do_async_tx
>   1.413 seconds (  0.27%) :  netconn_recv_data
>   1.335 seconds (  0.26%) :  etharp_output
>   1.321 seconds (  0.26%) :  do_recv
>   1.291 seconds (  0.25%) :  tcp_output_alloc_header
>   1.178 seconds (  0.23%) :  sys_arch_unprotect
>   1.175 seconds (  0.23%) :  _os21_scheduler_unlock
>   1.162 seconds (  0.23%) :  inet_chksum_pseudo
>   1.105 seconds (  0.21%) :  sys_arch_protect
>   1.090 seconds (  0.21%) :  semaphore_signal
>   1.086 seconds (  0.21%) :  sys_arch_sem_wait
>   1.073 seconds (  0.21%) :  sys_mbox_trypost
>   1.032 seconds (  0.20%) :  _os21_is_active
>   1.011 seconds (  0.20%) :  locate_handle
>   1.011 seconds (  0.20%) :  rx_task
>   0.982 seconds (  0.19%) :  tcp_recved
>   0.950 seconds (  0.18%) :  release_handle
>   0.947 seconds (  0.18%) :  __libc_lock_release_recursive
>   0.934 seconds (  0.18%) :  message_claim_timeout
>   0.922 seconds (  0.18%) :  tcp_parseopt
>   0.908 seconds (  0.18%) :  message_send
>   0.899 seconds (  0.17%) :  claim_handle
>   0.885 seconds (  0.17%) :  inet_chksum
>   0.881 seconds (  0.17%) :  ip_output
>   0.875 seconds (  0.17%) :  interrupt_mask
>   0.787 seconds (  0.15%) :  __libc_lock_acquire_recursive
>   0.786 seconds (  0.15%) :  pbuf_cat
>   0.760 seconds (  0.15%) :  time_now_set
>   0.728 seconds (  0.14%) :  tcpip_input
>   0.712 seconds (  0.14%) :  _os21_scheduler_exception_context
>   0.680 seconds (  0.13%) :  handle_frame
>   0.660 seconds (  0.13%) :  pbuf_free
>   0.621 seconds (  0.12%) :  osplus_handle
>   0.620 seconds (  0.12%) :  raw_input
>   0.607 seconds (  0.12%) :  icmp_input
>   0.584 seconds (  0.11%) :  _os21_vmem_util_min_page_size
>   0.584 seconds (  0.11%) :  message_release
>   0.568 seconds (  0.11%) :  ethernet_ops_do_async_rx
>   0.564 seconds (  0.11%) :  _md_timer_profiling_hz
>   0.563 seconds (  0.11%) :  netconn_recved
>   0.553 seconds (  0.11%) :  tcpip_thread
>   0.543 seconds (  0.11%) :  _os21_callback_intr_enter
>   0.530 seconds (  0.10%) :  malloc
>   0.510 seconds (  0.10%) :  pbuf_pool_is_empty
>   0.485 seconds (  0.09%) :  task_unlock
>   0.474 seconds (  0.09%) :  lwip_htons
>   0.473 seconds (  0.09%) :  netconn_recv_tcp_pbuf
>   0.435 seconds (  0.08%) :  lwip_read
>   0.434 seconds (  0.08%) :  sys_sem_signal
>   0.424 seconds (  0.08%) :  tcp_send_empty_ack
>   0.420 seconds (  0.08%) :  _os21_scheduler_pri
>   0.401 seconds (  0.08%) :  pbuf_take
>   0.396 seconds (  0.08%) :  low_level_output
>   0.387 seconds (  0.08%) :  lwip_close
>   0.375 seconds (  0.07%) :  task_lock
>   0.350 seconds (  0.07%) :  inet_chksum_pseudo_partial
>   0.340 seconds (  0.07%) :  wrapper
>   0.329 seconds (  0.06%) :  ip_route
>   0.319 seconds (  0.06%) :  tcp_update_rcv_ann_wnd
>   0.259 seconds (  0.05%) :  _scheduler_idle
>   0.253 seconds (  0.05%) :  release_buffer
>   0.252 seconds (  0.05%) :  mac_link_callback
>   0.234 seconds (  0.05%) :  lwip_ntohs
>   0.233 seconds (  0.05%) :  vmem_min_page_size
>   0.217 seconds (  0.04%) :  netconn_getaddr
>   0.217 seconds (  0.04%) :  _md_kernel_text_info
>   0.208 seconds (  0.04%) :  stxmac_dma_rx_abort
>   0.206 seconds (  0.04%) :  tcpip_apimsg
>   0.202 seconds (  0.04%) :  virtlay_NotifyDisplaySettings
>   0.196 seconds (  0.04%) :  lwip_ntohl
>   0.148 seconds (  0.03%) :  pbuf_realloc
>   0.139 seconds (  0.03%) :  _os21_kernel_state
>   0.135 seconds (  0.03%) :  stvtg_InterruptHandler
>   0.134 seconds (  0.03%) :  free
>   0.125 seconds (  0.02%) :  stevt_CallBothNotifyCB
>   0.124 seconds (  0.02%) :  _os21_callback_intr_exit
>   0.093 seconds (  0.02%) :  netconn_gethostbyname
>   0.089 seconds (  0.02%) :  etharp_send_ip
>   0.077 seconds (  0.01%) :  time_plus
>   0.073 seconds (  0.01%) :  sys_mbox_post
>   0.068 seconds (  0.01%) :  STEVT_NotifyWithSize
>   0.061 seconds (  0.01%) :  lwip_htonl
>   0.053 seconds (  0.01%) :  semaphore_value
>   0.051 seconds (  0.01%) :  VDP_IsUpdateNeeded
>   0.048 seconds (  0.01%) :  sys_arch_mbox_tryfetch
>   0.042 seconds (  0.01%) :  time_ticks_per_sec
>   0.042 seconds (  0.01%) :  device_check_args
>   0.042 seconds (  0.01%) :  LayerVideo_VSync
>   0.040 seconds (  0.01%) :  vdp_NotifyDisplaySettings
>   0.039 seconds (  0.01%) :  stlayer_VSyncCallback
>   0.033 seconds (  0.01%) :  STOS_SemaphoreSignal
>   0.028 seconds (  0.01%) :  ipaddr_ntoa_r
>   0.025 seconds (  0.00%) :  stevt_CheckID
>   0.024 seconds (  0.00%) :  task_context
>   0.023 seconds (  0.00%) :  EventChange
>   0.021 seconds (  0.00%) :  FastHardwareManagerTask
>   0.016 seconds (  0.00%) :  STDVMi_ServiceTask
>   0.015 seconds (  0.00%) :  lwip_recv
>   0.012 seconds (  0.00%) :  stxmac_phy_busy_wait
>   0.012 seconds (  0.00%) :  STOS_SemaphoreWaitTimeOut
>   0.010 seconds (  0.00%) :  VIRTLAY_IsUpdateNeeded
>   0.010 seconds (  0.00%) :  stlayer_HardwareManagerTerm
>   0.008 seconds (  0.00%) :  _malloc_trim_r
>   0.007 seconds (  0.00%) :  etharp_query