Re: [REGRESSION] NFS is creating a hidden port (left over from xs_bind() )
From: Steven Rostedt
Date: Fri Jun 19 2015 - 13:18:11 EST
On Fri, 19 Jun 2015 12:25:53 -0400
Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
> I don't see that 55201 anywhere. But then again, I didn't look for it
> before the port disappeared. I could reboot and look for it again. I
> should have saved the full netstat -tapn as well :-/
Of course I didn't find it anywhere, that's the port on my wife's box
that port 947 was connected to.
Now I even went over to my wife's box and ran
# rpcinfo -p localhost
program vers proto port service
100000 4 tcp 111 portmapper
100000 3 tcp 111 portmapper
100000 2 tcp 111 portmapper
100000 4 udp 111 portmapper
100000 3 udp 111 portmapper
100000 2 udp 111 portmapper
100024 1 udp 34243 status
100024 1 tcp 34498 status
which doesn't show anything.
but something is listening to that port...
# netstat -ntap |grep 55201
tcp 0 0 0.0.0.0:55201 0.0.0.0:* LISTEN
I rebooted again, but this time I ran this on my wife's box:
# trace-cmd record -e nfs -e nfs4 -e net -e skb -e sock -e udp -e workqueue -e sunrpc
I started it when my server started booting the kernel, and kept it
running till the port vanished.
The full trace can be downloaded from
http://rostedt.homelinux.com/private/wife-trace.txt
Here's some interesting output from that trace:
ksoftirq-13 1..s. 12272627.681760: netif_receive_skb: dev=lo skbaddr=0xffff88020944c600 len=88
ksoftirq-13 1..s. 12272627.681776: net_dev_queue: dev=eth0 skbaddr=0xffff880234e5b100 len=42
ksoftirq-13 1..s. 12272627.681777: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff880234e5b100 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0806 ip_
summed=0 len=42 data_len=0 network_offset=14 transport_offset_valid=0 transport_offset=65533 tx_flags=0 gso_size=0 gso_segs=0 gso_type=0
ksoftirq-13 1..s. 12272627.681779: net_dev_xmit: dev=eth0 skbaddr=0xffff880234e5b100 len=42 rc=0
ksoftirq-13 1..s. 12272627.681780: kfree_skb: skbaddr=0xffff88023444cf00 protocol=2048 location=0xffffffff81422a72
ksoftirq-13 1..s. 12272627.681783: rpc_socket_error: error=-113 socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=2 ()
ksoftirq-13 1..s. 12272627.681785: rpc_task_wakeup: task:18128@0 flags=5281 state=0006 status=-113 timeout=45000 queue=xprt_pending
ksoftirq-13 1d.s. 12272627.681786: workqueue_queue_work: work struct=0xffff8800b5a94588 function=rpc_async_schedule workqueue=0xffff880234666800 req_cpu=512 cpu=1
ksoftirq-13 1d.s. 12272627.681787: workqueue_activate_work: work struct 0xffff8800b5a94588
ksoftirq-13 1..s. 12272627.681791: rpc_socket_state_change: socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=7 ()
ksoftirq-13 1..s. 12272627.681792: kfree_skb: skbaddr=0xffff88020944c600 protocol=2048 location=0xffffffff81482c05
kworker/-20111 1.... 12272627.681796: workqueue_execute_start: work struct 0xffff8800b5a94588: function rpc_async_schedule
kworker/-20111 1.... 12272627.681797: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-113 action=call_connect_status
kworker/-20111 1.... 12272627.681798: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-113 action=call_connect_status
kworker/-20111 1.... 12272627.681798: rpc_connect_status: task:18128@0, status -113
kworker/-20111 1..s. 12272627.681799: rpc_task_sleep: task:18128@0 flags=5281 state=0005 status=0 timeout=750 queue=delayq
kworker/-20111 1.... 12272627.681800: workqueue_execute_end: work struct 0xffff8800b5a94588
<idle>-0 1..s. 12272630.688741: rpc_task_wakeup: task:18128@0 flags=5281 state=0006 status=-110 timeout=750 queue=delayq
<idle>-0 1dNs. 12272630.688749: workqueue_queue_work: work struct=0xffff8800b5a94588 function=rpc_async_schedule workqueue=0xffff880234666800 req_cpu=512 cpu=1
<idle>-0 1dNs. 12272630.688749: workqueue_activate_work: work struct 0xffff8800b5a94588
kworker/-20111 1.... 12272630.688758: workqueue_execute_start: work struct 0xffff8800b5a94588: function rpc_async_schedule
kworker/-20111 1.... 12272630.688759: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-110 action=call_timeout
kworker/-20111 1.... 12272630.688760: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_timeout
kworker/-20111 1.... 12272630.688760: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_bind
kworker/-20111 1.... 12272630.688761: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_connect
kworker/-20111 1..s. 12272630.688762: rpc_task_sleep: task:18128@0 flags=5281 state=0005 status=0 timeout=45000 queue=xprt_pending
kworker/-20111 1.... 12272630.688765: workqueue_execute_end: work struct 0xffff8800b5a94588
<idle>-0 3d.s. 12272630.696742: workqueue_queue_work: work struct=0xffff880234ac9060 function=disk_events_workfn workqueue=0xffff8802370d9000 req_cpu=512 cpu=3
<idle>-0 3d.s. 12272630.696744: workqueue_activate_work: work struct 0xffff880234ac9060
kworker/-7491 3.... 12272630.696760: workqueue_execute_start: work struct 0xffff880234ac9060: function disk_events_workfn
kworker/-7491 3d... 12272630.696827: workqueue_queue_work: work struct=0xffff8802347440b8 function=ata_sff_pio_task workqueue=0xffff880234491c00 req_cpu=512 cpu=3
kworker/-7491 3d... 12272630.696828: workqueue_activate_work: work struct 0xffff8802347440b8
kworker/-16140 3.... 12272630.696837: workqueue_execute_start: work struct 0xffff8802347440b8: function ata_sff_pio_task
kworker/-16140 3.... 12272630.696853: workqueue_execute_end: work struct 0xffff8802347440b8
kworker/-7491 3.... 12272630.697383: workqueue_execute_end: work struct 0xffff880234ac9060
<idle>-0 1d.s. 12272654.753029: workqueue_queue_work: work struct=0xffff8802361f4de0 function=xs_tcp_setup_socket workqueue=0xffff880234666800 req_cpu=512 cpu=1
<idle>-0 1d.s. 12272654.753031: workqueue_activate_work: work struct 0xffff8802361f4de0
kworker/-20111 1.... 12272654.753049: workqueue_execute_start: work struct 0xffff8802361f4de0: function xs_tcp_setup_socket
kworker/-20111 1..s. 12272654.753054: rpc_socket_error: error=-113 socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=7 ()
kworker/-20111 1.... 12272654.753055: rpc_socket_reset_connection: error=0 socket:[11886206] dstaddr=192.168.23.9/2049 state=1 () sk_state=7 ()
kworker/-20111 1..s. 12272654.753075: net_dev_queue: dev=eth0 skbaddr=0xffff880082117ae8 len=74
kworker/-20111 1..s. 12272654.753083: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff880082117ae8 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 len=74 data_len=0 network_offset=14 transport_offset_valid=1 transport_offset=34 tx_flags=0 gso_size=0 gso_segs=1 gso_type=0
kworker/-20111 1..s. 12272654.753088: net_dev_xmit: dev=eth0 skbaddr=0xffff880082117ae8 len=74 rc=0
kworker/-20111 1.... 12272654.753090: rpc_socket_connect: error=-115 socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=2 ()
kworker/-20111 1.... 12272654.753093: workqueue_execute_end: work struct 0xffff8802361f4de0
<idle>-0 1..s. 12272654.753320: consume_skb: skbaddr=0xffff880082117ae8
<idle>-0 1..s. 12272654.753503: napi_gro_receive_entry: dev=eth0 napi_id=0 queue_mapping=0 skbaddr=0xffff8801f647d100 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0806 ip_summed=0 hash=0x00000000 l4_hash=0 len=46 data_len=0 truesize=704 mac_header_valid=1 mac_header=-14 nr_frags=0 gso_size=0 gso_type=0
<idle>-0 1.Ns. 12272654.753508: netif_receive_skb: dev=eth0 skbaddr=0xffff8801f647d100 len=46
<idle>-0 1.Ns. 12272654.753519: consume_skb: skbaddr=0xffff8800a9aa2d00
<idle>-0 1.Ns. 12272654.753522: net_dev_queue: dev=eth0 skbaddr=0xffff8800a9aa2d00 len=42
<idle>-0 1.Ns. 12272654.753523: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff8800a9aa2d00 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0806 ip_summed=0 len=42 data_len=0 network_offset=14 transport_offset_valid=0 transport_offset=65533 tx_flags=0 gso_size=0 gso_segs=0 gso_type=0
<idle>-0 1.Ns. 12272654.753525: net_dev_xmit: dev=eth0 skbaddr=0xffff8800a9aa2d00 len=42 rc=0
<idle>-0 1.Ns. 12272654.753526: consume_skb: skbaddr=0xffff8801f647d100
<idle>-0 1..s. 12272654.753585: napi_gro_receive_entry: dev=eth0 napi_id=0 queue_mapping=0 skbaddr=0xffff8801f647d100 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=1 hash=0x00000000 l4_hash=0 len=46 data_len=0 truesize=704 mac_header_valid=1 mac_header=-14 nr_frags=0 gso_size=0 gso_type=0
<idle>-0 1.Ns. 12272654.753589: netif_receive_skb: dev=eth0 skbaddr=0xffff8801f647d100 len=46
<idle>-0 1.Ns. 12272654.753595: rpc_socket_error: error=-111 socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=2 ()
<idle>-0 1.Ns. 12272654.753597: rpc_task_wakeup: task:18128@0 flags=5281 state=0006 status=-111 timeout=45000 queue=xprt_pending
<idle>-0 1dNs. 12272654.753598: workqueue_queue_work: work struct=0xffff8800b5a94588 function=rpc_async_schedule workqueue=0xffff880234666800 req_cpu=512 cpu=1
<idle>-0 1dNs. 12272654.753599: workqueue_activate_work: work struct 0xffff8800b5a94588
<idle>-0 1.Ns. 12272654.753601: rpc_socket_state_change: socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=7 ()
kworker/-20111 1.... 12272654.753607: workqueue_execute_start: work struct 0xffff8800b5a94588: function rpc_async_schedule
kworker/-20111 1.... 12272654.753608: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-111 action=call_connect_status
kworker/-20111 1.... 12272654.753609: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-111 action=call_connect_status
kworker/-20111 1.... 12272654.753609: rpc_connect_status: task:18128@0, status -111
kworker/-20111 1..s. 12272654.753610: rpc_task_sleep: task:18128@0 flags=5281 state=0005 status=0 timeout=750 queue=delayq
kworker/-20111 1.... 12272654.753612: workqueue_execute_end: work struct 0xffff8800b5a94588
<idle>-0 1..s. 12272654.753692: consume_skb: skbaddr=0xffff8800a9aa2d00
<idle>-0 1.Ns. 12272657.605105: netif_receive_skb: dev=eth0 skbaddr=0xffff8802223d1e00 len=345
<idle>-0 1.Ns. 12272657.605108: kfree_skb: skbaddr=0xffff8802223d1e00 protocol=2048 location=0xffffffff8147e361
<idle>-0 1..s. 12272657.760044: rpc_task_wakeup: task:18128@0 flags=5281 state=0006 status=-110 timeout=750 queue=delayq
<idle>-0 1dNs. 12272657.760051: workqueue_queue_work: work struct=0xffff8800b5a94588 function=rpc_async_schedule workqueue=0xffff880234666800 req_cpu=512 cpu=1
<idle>-0 1dNs. 12272657.760052: workqueue_activate_work: work struct 0xffff8800b5a94588
kworker/-20111 1.... 12272657.760063: workqueue_execute_start: work struct 0xffff8800b5a94588: function rpc_async_schedule
kworker/-20111 1.... 12272657.760064: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-110 action=call_timeout
kworker/-20111 1.... 12272657.760065: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_timeout
kworker/-20111 1.... 12272657.760066: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_bind
kworker/-20111 1.... 12272657.760066: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_connect
kworker/-20111 1..s. 12272657.760068: rpc_task_sleep: task:18128@0 flags=5281 state=0005 status=0 timeout=45000 queue=xprt_pending
kworker/-20111 1.... 12272657.760070: workqueue_execute_end: work struct 0xffff8800b5a94588
<idle>-0 3d.s. 12272657.824024: workqueue_queue_work: work struct=0xffff8800b5551760 function=disk_events_workfn workqueue=0xffff8802370d9000 req_cpu=512 cpu=3
<idle>-0 3d.s. 12272657.824025: workqueue_activate_work: work struct 0xffff8800b5551760
kworker/-7491 3.... 12272657.824041: workqueue_execute_start: work struct 0xffff8800b5551760: function disk_events_workfn
kworker/-7491 3.... 12272657.824807: workqueue_execute_end: work struct 0xffff8800b5551760
<idle>-0 1d.s. 12272705.808564: workqueue_queue_work: work struct=0xffff8802361f4de0 function=xs_tcp_setup_socket workqueue=0xffff880234666800 req_cpu=512 cpu=1
<idle>-0 1d.s. 12272705.808565: workqueue_activate_work: work struct 0xffff8802361f4de0
kworker/-20111 1.... 12272705.808574: workqueue_execute_start: work struct 0xffff8802361f4de0: function xs_tcp_setup_socket
kworker/-20111 1..s. 12272705.808580: rpc_socket_error: error=-111 socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=7 ()
kworker/-20111 1.... 12272705.808581: rpc_socket_reset_connection: error=0 socket:[11886206] dstaddr=192.168.23.9/2049 state=1 () sk_state=7 ()
kworker/-20111 1..s. 12272705.808599: net_dev_queue: dev=eth0 skbaddr=0xffff880082117ae8 len=74
kworker/-20111 1..s. 12272705.808602: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff880082117ae8 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 len=74 data_len=0 network_offset=14 transport_offset_valid=1 transport_offset=34 tx_flags=0 gso_size=0 gso_segs=1 gso_type=0
kworker/-20111 1..s. 12272705.808605: net_dev_xmit: dev=eth0 skbaddr=0xffff880082117ae8 len=74 rc=0
kworker/-20111 1.... 12272705.808614: rpc_socket_connect: error=-115 socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=2 ()
kworker/-20111 1.... 12272705.808615: workqueue_execute_end: work struct 0xffff8802361f4de0
<idle>-0 1..s. 12272705.808841: napi_gro_receive_entry: dev=eth0 napi_id=0 queue_mapping=0 skbaddr=0xffff8800a60e8900 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=1 hash=0x00000000 l4_hash=0 len=60 data_len=0 truesize=768 mac_header_valid=1 mac_header=-14 nr_frags=0 gso_size=0 gso_type=0
<idle>-0 1.Ns. 12272705.808849: netif_receive_skb: dev=eth0 skbaddr=0xffff8800a60e8900 len=60
<idle>-0 1.Ns. 12272705.808872: rpc_socket_state_change: socket:[11886206] dstaddr=192.168.23.9/2049 state=2 () sk_state=1 ()
<idle>-0 1.Ns. 12272705.808874: rpc_task_wakeup: task:18128@0 flags=5281 state=0006 status=-11 timeout=45000 queue=xprt_pending
<idle>-0 1dNs. 12272705.808875: workqueue_queue_work: work struct=0xffff8800b5a94588 function=rpc_async_schedule workqueue=0xffff880234666800 req_cpu=512 cpu=1
<idle>-0 1dNs. 12272705.808876: workqueue_activate_work: work struct 0xffff8800b5a94588
<idle>-0 1.Ns. 12272705.808881: net_dev_queue: dev=eth0 skbaddr=0xffff8800a60e8500 len=66
<idle>-0 1.Ns. 12272705.808883: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff8800a60e8500 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 len=66 data_len=0 network_offset=14 transport_offset_valid=1 transport_offset=34 tx_flags=0 gso_size=0 gso_segs=1 gso_type=0
<idle>-0 1.Ns. 12272705.808885: net_dev_xmit: dev=eth0 skbaddr=0xffff8800a60e8500 len=66 rc=0
<idle>-0 1.Ns. 12272705.808887: consume_skb: skbaddr=0xffff880082117ae8
kworker/-20111 1.... 12272705.808895: workqueue_execute_start: work struct 0xffff8800b5a94588: function rpc_async_schedule
kworker/-20111 1.... 12272705.808896: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-11 action=call_connect_status
kworker/-20111 1.... 12272705.808897: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=-11 action=call_connect_status
kworker/-20111 1.... 12272705.808897: rpc_connect_status: task:18128@0, status -11
kworker/-20111 1.... 12272705.808897: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_timeout
kworker/-20111 1.... 12272705.808898: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_bind
kworker/-20111 1.... 12272705.808899: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_connect
kworker/-20111 1.... 12272705.808899: rpc_task_run_action: task:18128@0 flags=5281 state=0005 status=0 action=call_transmit
kworker/-20111 1..s. 12272705.808912: net_dev_queue: dev=eth0 skbaddr=0xffff880082117ae8 len=162
kworker/-20111 1..s. 12272705.808913: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff880082117ae8 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 len=162 data_len=0 network_offset=14 transport_offset_valid=1 transport_offset=34 tx_flags=0 gso_size=0 gso_segs=1 gso_type=0
kworker/-20111 1..s. 12272705.808913: net_dev_xmit: dev=eth0 skbaddr=0xffff880082117ae8 len=162 rc=0
kworker/-20111 1..s. 12272705.808916: rpc_task_sleep: task:18128@0 flags=5a81 state=0005 status=0 timeout=45000 queue=xprt_pending
kworker/-20111 1.... 12272705.808917: workqueue_execute_end: work struct 0xffff8800b5a94588
<idle>-0 1..s. 12272705.809098: consume_skb: skbaddr=0xffff8800a60e8500
<idle>-0 1.Ns. 12272705.809840: rpc_task_wakeup: task:18128@0 flags=5a81 state=0006 status=0 timeout=45000 queue=xprt_pending
<idle>-0 1dNs. 12272705.809842: workqueue_queue_work: work struct=0xffff8800b5a94588 function=rpc_async_schedule workqueue=0xffff880234666800 req_cpu=512 cpu=1
<idle>-0 1dNs. 12272705.809842: workqueue_activate_work: work struct 0xffff8800b5a94588
kworker/-20111 1.... 12272705.809853: workqueue_execute_start: work struct 0xffff8800b5a94588: function rpc_async_schedule
kworker/-20111 1.... 12272705.809853: rpc_task_run_action: task:18128@0 flags=5a81 state=0005 status=0 action=call_status
kworker/-20111 1.... 12272705.809854: rpc_task_run_action: task:18128@0 flags=5a81 state=0005 status=0 action=call_status
kworker/-20111 1.... 12272705.809854: rpc_task_run_action: task:18128@0 flags=5a81 state=0005 status=44 action=call_decode
kworker/-20111 1.... 12272705.809856: rpc_task_run_action: task:18128@0 flags=5a81 state=0005 status=-10022 action=rpc_exit_task
kworker/-20111 1.... 12272705.809858: nfs4_renew_async: error=-10022 () dstaddr=192.168.23.9
<idle>-0 1.Ns. 12272705.810000: consume_skb: skbaddr=0xffff8800a60e8900
kworker/-20111 1.... 12272705.810033: workqueue_execute_end: work struct 0xffff8800b5a94588
192.168.-16171 3.... 12272705.810062: rpc_task_begin: task:0@0 flags=5280 state=0000 status=0 action=irq_stack_union
192.168.-16171 3.... 12272705.810068: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_start
192.168.-16171 3.... 12272705.810069: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_reserve
192.168.-16171 3.... 12272705.810071: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_reserveresult
192.168.-16171 3.... 12272705.810071: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_refresh
192.168.-16171 3.... 12272705.810073: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_refreshresult
192.168.-16171 3.... 12272705.810073: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_allocate
192.168.-16171 3.... 12272705.810074: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_bind
192.168.-16171 3.... 12272705.810075: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_connect
192.168.-16171 3.... 12272705.810075: rpc_task_run_action: task:18129@0 flags=5280 state=0005 status=0 action=call_transmit
192.168.-16171 3..s. 12272705.810095: net_dev_queue: dev=eth0 skbaddr=0xffff8800a9b924e8 len=162
192.168.-16171 3..s. 12272705.810097: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff8800a9b924e8 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 len=162 data_len=0 network_offset=14 transport_offset_valid=1 transport_offset=34 tx_flags=0 gso_size=0 gso_segs=1 gso_type=0
192.168.-16171 3..s. 12272705.810098: net_dev_xmit: dev=eth0 skbaddr=0xffff8800a9b924e8 len=162 rc=0
192.168.-16171 3..s. 12272705.810101: rpc_task_sleep: task:18129@0 flags=5a80 state=0005 status=0 timeout=15000 queue=xprt_pending
<idle>-0 1..s. 12272705.810318: napi_gro_receive_entry: dev=eth0 napi_id=0 queue_mapping=0 skbaddr=0xffff8800a60e8900 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=1 hash=0x00000000 l4_hash=0 len=100 data_len=0 truesize=768 mac_header_valid=1 mac_header=-14 nr_frags=0 gso_size=0 gso_type=0
<idle>-0 1.Ns. 12272705.810326: netif_receive_skb: dev=eth0 skbaddr=0xffff8800a60e8900 len=100
<idle>-0 1.Ns. 12272705.810344: rpc_task_wakeup: task:18129@0 flags=5a80 state=0006 status=0 timeout=15000 queue=xprt_pending
<idle>-0 1.Ns. 12272705.810349: consume_skb: skbaddr=0xffff8800a9b924e8
192.168.-16171 3.... 12272705.810379: rpc_task_run_action: task:18129@0 flags=5a80 state=0005 status=0 action=call_status
192.168.-16171 3.... 12272705.810385: rpc_task_run_action: task:18129@0 flags=5a80 state=0005 status=0 action=call_status
192.168.-16171 3.... 12272705.810385: rpc_task_run_action: task:18129@0 flags=5a80 state=0005 status=44 action=call_decode
192.168.-16171 3.... 12272705.810387: rpc_task_run_action: task:18129@0 flags=5a80 state=0005 status=-10022 action=rpc_exit_task
192.168.-16171 3.... 12272705.810397: rpc_task_begin: task:0@0 flags=5280 state=0000 status=0 action=irq_stack_union
192.168.-16171 3.... 12272705.810398: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_start
192.168.-16171 3.... 12272705.810398: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_reserve
192.168.-16171 3.... 12272705.810399: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_reserveresult
192.168.-16171 3.... 12272705.810399: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_refresh
192.168.-16171 3.... 12272705.810400: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_refreshresult
192.168.-16171 3.... 12272705.810400: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_allocate
192.168.-16171 3.... 12272705.810404: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_bind
192.168.-16171 3.... 12272705.810404: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_connect
192.168.-16171 3.... 12272705.810404: rpc_task_run_action: task:18130@0 flags=5280 state=0005 status=0 action=call_transmit
192.168.-16171 3..s. 12272705.810417: net_dev_queue: dev=eth0 skbaddr=0xffff8800a9b92ae8 len=254
192.168.-16171 3..s. 12272705.810418: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff8800a9b92ae8 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 len=254 data_len=0 network_offset=14 transport_offset_valid=1 transport_offset=34 tx_flags=0 gso_size=0 gso_segs=1 gso_type=0
192.168.-16171 3..s. 12272705.810426: net_dev_xmit: dev=eth0 skbaddr=0xffff8800a9b92ae8 len=254 rc=0
192.168.-16171 3..s. 12272705.810428: rpc_task_sleep: task:18130@0 flags=5a80 state=0005 status=0 timeout=15000 queue=xprt_pending
192.168.-16171 3.... 12272705.810902: rpc_task_run_action: task:18130@0 flags=5a80 state=0005 status=0 action=call_status
192.168.-16171 3.... 12272705.810908: rpc_task_run_action: task:18130@0 flags=5a80 state=0005 status=0 action=call_status
192.168.-16171 3.... 12272705.810908: rpc_task_run_action: task:18130@0 flags=5a80 state=0005 status=60 action=call_decode
192.168.-16171 3.... 12272705.810910: rpc_task_run_action: task:18130@0 flags=5a80 state=0005 status=0 action=rpc_exit_task
192.168.-16171 3.... 12272705.810914: nfs4_setclientid: error=0 (ACCESS) dstaddr=192.168.23.9
192.168.-16171 3.... 12272705.810915: rpc_task_begin: task:0@0 flags=5280 state=0000 status=0 action=irq_stack_union
192.168.-16171 3.... 12272705.810916: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_start
192.168.-16171 3.... 12272705.810916: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_reserve
192.168.-16171 3.... 12272705.810917: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_reserveresult
192.168.-16171 3.... 12272705.810917: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_refresh
192.168.-16171 3.... 12272705.810918: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_refreshresult
192.168.-16171 3.... 12272705.810918: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_allocate
192.168.-16171 3.... 12272705.810919: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_bind
192.168.-16171 3.... 12272705.810919: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_connect
192.168.-16171 3.... 12272705.810919: rpc_task_run_action: task:18131@0 flags=5280 state=0005 status=0 action=call_transmit
192.168.-16171 3..s. 12272705.810931: net_dev_queue: dev=eth0 skbaddr=0xffff8800a9b92ce8 len=170
192.168.-16171 3..s. 12272705.810932: net_dev_start_xmit: dev=eth0 queue_mapping=0 skbaddr=0xffff8800a9b92ce8 vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 len=170 data_len=0 network_offset=14 transport_offset_valid=1 transport_offset=34 tx_flags=0 gso_size=0 gso_segs=1 gso_type=0
192.168.-16171 3..s. 12272705.810933: net_dev_xmit: dev=eth0 skbaddr=0xffff8800a9b92ce8 len=170 rc=0
192.168.-16171 3..s. 12272705.810936: rpc_task_sleep: task:18131@0 flags=5a80 state=0005 status=0 timeout=15000 queue=xprt_pending
192.168.-16171 3.... 12272705.811213: rpc_task_run_action: task:18131@0 flags=5a80 state=0005 status=0 action=call_status
192.168.-16171 3.... 12272705.811220: rpc_task_run_action: task:18131@0 flags=5a80 state=0005 status=0 action=call_status
192.168.-16171 3.... 12272705.811220: rpc_task_run_action: task:18131@0 flags=5a80 state=0005 status=44 action=call_decode
192.168.-16171 3.... 12272705.811222: rpc_task_run_action: task:18131@0 flags=5a80 state=0005 status=0 action=rpc_exit_task
192.168.-16171 3.... 12272705.811227: nfs4_setclientid_confirm: error=0 (ACCESS) dstaddr=192.168.23.9
And it goes on, but you can look at the full trace. I just searched
for "rpc".
Maybe this will shed more light on the issue. I'll keep this kernel on
my server for a little longer, but it's going to start triggering
rkhunter warnings about hidden ports again.
-- Steve
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
Please read the FAQ at http://www.tux.org/lkml/