contrail-vrouter-dpdk crash with signal SIGSEGV @dpdk_adjust_tcp_mss

[Jiang Lu]

Field reported contrail-vrouter-dpdk crash with signal SIGSEGV @dpdk_adjust_tcp_mss on Contrail 3.2.9

vrouter-dpdk and vrouter-agent core files now uploaded at 10.85.180.80 (comp80) /root/jlu/2018-0413-0535/

root@bcomp80:~/jlu/2018-0413-0535# ls -alF
total 5324056
drwxr-xr-x 2 root root 4096 Apr 13 14:10 ./
drwx------ 7 root root 4096 Apr 13 13:40 ../
-rw-r--r-- 1 root root 479736974 Mar 4 10:20 contrail-vrouter-agent
-rw-r--r-- 1 root root 17885993 Mar 4 10:58 contrail-vrouter-dpdk
-rw------- 1 root root 1521876992 Apr 10 06:57 core.contrail-vroute.80654.mtn6r03c005.mtn6.cci.att.com.1523368630
-rw------- 1 root root 3432312832 Apr 10 06:56 core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617

root@bcomp80:~/jlu/2018-0413-0535# gdb contrail-vrouter-dpdk core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617
...
Core was generated by `/usr/bin/contrail-vrouter-dpdk --no-daemon --vr_flow_entries=2097152 --vr_mpls_'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 dpdk_adjust_tcp_mss (tcph=0x7f2938ce8c92, overlay_len=overlay_len@entry=62, iph_len=iph_len@entry=20 '\024') at vrouter/dpdk/vr_dpdk_host.c:889
889 vrouter/dpdk/vr_dpdk_host.c: No such file or directory.
(gdb) bt
#0 dpdk_adjust_tcp_mss (tcph=0x7f2938ce8c92, overlay_len=overlay_len@entry=62, iph_len=iph_len@entry=20 '\024') at vrouter/dpdk/vr_dpdk_host.c:889
#1 0x0000000000534371 in dpdk_pkt_from_vm_tcp_mss_adj (pkt=0x7f2938ce8b40, overlay_len=<optimized out>) at vrouter/dpdk/vr_dpdk_host.c:986
#2 0x000000000054f058 in vr_bridge_input (router=<optimized out>, pkt=0x7f2938ce8b40, fmd=0x7f4315e725b0) at vrouter/dp-core/vr_bridge.c:614
#3 0x0000000000552ed5 in vr_flow_flush_pnode (fmd=0x7f4315e725b0, fe=0x2aaacd737800, pnode=0x7f292ebc6a48, router=0x55e17c0 <router>) at vrouter/dp-core/vr_flow.c:1534
#4 __vr_flow_flush_hold_queue (vfq=<optimized out>, fmd=<optimized out>, fe=<optimized out>, router=<optimized out>) at vrouter/dp-core/vr_flow.c:1548
#5 vr_flush_entry (flmd=<optimized out>, fmd=0x7f4315e725b0, fe=0x2aaacd737800, router=0x55e17c0 <router>) at vrouter/dp-core/vr_flow.c:1571
#6 __vr_flow_work (flmd=0x7f292ebc69c0, fe=0x2aaacd737800, router=0x55e17c0 <router>) at vrouter/dp-core/vr_flow.c:1596
#7 vr_flow_work (arg=0x7f292ebc69c0, arg@entry=<error reading variable: value has been optimized out>) at vrouter/dp-core/vr_flow.c:1619
#8 0x000000000052f529 in dpdk_schedule_work (cpu=<optimized out>, fn=<optimized out>, arg=<optimized out>) at vrouter/dpdk/vr_dpdk_host.c:512
#9 0x0000000000553dd3 in vr_flow_schedule_transition (req=<optimized out>, req=<optimized out>, fe=0x2aaacd737800, router=0x55e17c0 <router>) at vrouter/dp-core/vr_flow.c:1926
#10 vr_flow_set (router=<optimized out>, flow_resp=0x7f4315e72680, req=0x7f430c001210) at vrouter/dp-core/vr_flow.c:2169
#11 vr_flow_req_process (s_req=0x7f430c001210) at vrouter/dp-core/vr_flow.c:2311
#12 0x000000000059db94 in sandesh_decode_one (error=0x7f4315e727b0, sinfo_find_fn=0x59d7e0 <vr_find_sandesh_info>, buf_len=262, buf=0x7f293039a4d8 "") at tools/sandesh/library/c/sandesh.c:105
#13 sandesh_decode (buf=0x7f293039a4d8 "", buf_len=262, sinfo_find_fn=0x59d7e0 <vr_find_sandesh_info>, error=error@entry=0x7f4315e727b0) at tools/sandesh/library/c/sandesh.c:133
#14 0x000000000056f7e8 in sandesh_proto_decode (buf=<optimized out>, len=<optimized out>, cb=<optimized out>, cb_arg=<optimized out>) at vrouter/dp-core/vr_sandesh.c:150
#15 0x0000000000561028 in vr_message_request (message=message@entry=0x7f4315e727e0) at vrouter/dp-core/vr_message.c:71
#16 0x000000000053f55d in dpdk_netlink_receive (usockp=usockp@entry=0x7f2930784280, nl_buf=0x7f293039a4c0 "\036\001", nl_len=<optimized out>) at vrouter/dpdk/vr_dpdk_netlink.c:106
#17 0x000000000054487a in usock_read_done (usockp=0x7f2930784280) at vrouter/dpdk/vr_dpdk_usocket.c:556
#18 vr_usocket_read (usockp=0x7f2930784280) at vrouter/dpdk/vr_dpdk_usocket.c:1025
#19 0x0000000000545b1d in vr_usocket_io (transport=<optimized out>) at vrouter/dpdk/vr_dpdk_usocket.c:1301
#20 0x000000000053eabd in dpdk_lcore_netlink_loop () at vrouter/dpdk/vr_dpdk_lcore.c:1580
#21 vr_dpdk_lcore_launch (dummy=<optimized out>) at vrouter/dpdk/vr_dpdk_lcore.c:1777
#22 0x00000000004425f5 in eal_thread_loop (arg=<optimized out>) at /home/contrail-builder/workspace/Nightly-Ubuntu-1404-Build/sandbox/third_party/dpdk/lib/librte_eal/linuxapp/eal/eal_thread.c:184
#23 0x00007f4318450184 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#24 0x00007f4317f75ffd in qfcvt_r () from /lib/x86_64-linux-gnu/libc.so.6
#25 0x0000000000000000 in ?? ()

root@bcomp80:~/jlu/2018-0413-0535# gdb contrail-vrouter-agent core.contrail-vroute.80654.mtn6r03c005.mtn6.cci.att.com.1523368630
...
Core was generated by `/usr/bin/contrail-vrouter-agent'.
Program terminated with signal SIGABRT, Aborted.
#0 0x00007fb726174c37 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) bt
#0 0x00007fb726174c37 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x0000000000002929 in ?? ()
#2 0x7328203c20746e63 in ?? ()
#3 0x5f2820666f657a69 in ?? ()
#4 0x65756c61765f6c6e in ?? ()
#5 0x434c5f657079745f in ?? ()
#6 0x524154454e4f4d5f in ?? ()
#7 0x7a6973202f202959 in ?? ()
#8 0x6c6e5f2820666f65 in ?? ()
#9 0x745f65756c61765f in ?? ()

mtn6r03c005:/var/log# contrail-version
Package Version Build-ID | Repo | Package Name
-------------------------------------- ------------------------------ ----------------------------------
contrail-lib 3.2.9.0-69 69
contrail-nodemgr 3.2.9.0-69 69
contrail-nova-vif 3.2.9.0-69 69
contrail-openstack-vrouter 3.2.9.0-69 69
contrail-setup 3.2.9.0-69 69
contrail-utils 3.2.9.0-69 69
contrail-vrouter-agent 3.2.9.0-69 69
contrail-vrouter-common 3.2.9.0-69 69
contrail-vrouter-dpdk 3.2.9.0-69 69
contrail-vrouter-dpdk-init 3.2.9.0-69 69
contrail-vrouter-init 69
contrail-vrouter-utils 3.2.9.0-69 69
nova-common 1:2015.1.0-1~u14.04.1-main34471+r3.0.3.8069
nova-compute 1:2015.1.0-1~u14.04.1-main34471+r3.0.3.8069
nova-compute-kvm 1:2015.1.0-1~u14.04.1-main34471+r3.0.3.8069
python-contrail 3.2.9.0-69 69
python-contrail-vrouter-api 3.2.9.0-69 69
python-neutronclient 1:2.4.0-1~u14.04.1-main769+r3.0.3.7 69
python-nova 1:2015.1.0-1~u14.04.1-main34471+r3.0.3.8069
python-opencontrail-vrouter-netns 3.2.9.0-69 69

mtn6r03c005:/var/log# contrail-status -d
== Contrail vRouter ==
supervisor-vrouter: active
contrail-vrouter-agent active pid 21136, uptime 0:59:20
contrail-vrouter-dpdk active pid 161586, uptime 3 days, 6:40:00
contrail-vrouter-nodemgr active pid 6885, uptime 18 days, 9:11:54

========Run time service failures=============
/var/crashes/core.qemu-system-x86.181831.mtn6r03c005.mtn6.cci.att.com.1522881178
/var/crashes/core.contrail-vroute.80654.mtn6r03c005.mtn6.cci.att.com.1523368630
/var/crashes/core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617 <<<<<

root@mtn6r03c005:~# cd /var/crashes/
root@mtn6r03c005:/var/crashes# ls -l
total 4947968
-rw------- 1 root root 1521876992 Apr 10 13:57 core.contrail-vroute.80654.mtn6r03c005.mtn6.cci.att.com.1523368630
-rw------- 1 root root 3432312832 Apr 10 13:56 core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617 <<<<

root@bcomp80:~/jlu# date -d @1523368617 <<<<
Tue Apr 10 06:56:57 PDT 2018
root@bcomp80:~/jlu# date -d @1523368630
Tue Apr 10 06:57:10 PDT 2018

/var/log/contrail/ uploaded at 10.85.180.80 (comp80) /root/jlu/2018-0413-0535/mtn6r03c005-var-log-contrail/

root@bcomp80:~/jlu/2018-0413-0535/mtn6r03c005-var-log-contrail# ls -alF
total 544524
drwxr-x--- 2 contrail adm 4096 Apr 13 14:53 ./
drwxr-xr-x 3 root root 4096 Apr 13 14:26 ../
-rw-r--r-- 1 contrail adm 12257 Apr 9 13:27 contrail-lbaas-haproxy-stdout.log
-rw-r--r-- 1 contrail adm 6158191 Apr 13 12:37 contrail-vrouter-agent-stdout.log
-rw-r--r-- 1 contrail adm 23852991 Apr 13 12:53 contrail-vrouter-dpdk-stdout.log <<<
-rw-r--r-- 1 root root 50484623 Apr 13 13:34 contrail-vrouter-nodemgr-stderr.log <<<
-rw-r--r-- 1 root root 52428814 Apr 5 08:23 contrail-vrouter-nodemgr-stderr.log.1
-rw-r--r-- 1 contrail contrail 52428814 Mar 26 21:39 contrail-vrouter-nodemgr-stderr.log.2
-rw-r--r-- 1 contrail adm 52428809 Mar 4 19:13 contrail-vrouter-nodemgr-stderr.log.3
-rw-r--r-- 1 contrail adm 52428843 Feb 9 17:22 contrail-vrouter-nodemgr-stderr.log.4
-rw-r--r-- 1 contrail adm 52428818 Jan 17 04:46 contrail-vrouter-nodemgr-stderr.log.5
-rw-r--r-- 1 contrail adm 52428804 Dec 25 04:35 contrail-vrouter-nodemgr-stderr.log.6
-rw-r--r-- 1 contrail adm 52428819 Dec 2 05:40 contrail-vrouter-nodemgr-stderr.log.7
-rw-r--r-- 1 contrail adm 52428852 Nov 8 07:27 contrail-vrouter-nodemgr-stderr.log.8
-rw-r--r-- 1 contrail adm 52428864 Oct 17 04:04 contrail-vrouter-nodemgr-stderr.log.9
-rw-r--r-- 1 contrail contrail 5085319 Apr 13 13:34 contrail-vrouter-nodemgr-stdout.log
-rw-r--r-- 1 contrail contrail 1556 Apr 13 12:37 process_statecontrail-vrouter.json
-rw-r--r-- 1 contrail adm 78677 Apr 13 12:37 supervisord-vrouter.log

supervisord-vrouter.log:

2018-03-29 21:05:38,691 INFO success: contrail-vrouter-agent entered RUNNING state, process has stayed up for > than 5 seconds (startsecs)
2018-04-10 13:57:09,672 INFO exited: contrail-vrouter-dpdk (terminated by SIGSEGV (core dumped); not expected)
2018-04-10 13:57:10,022 INFO spawned: 'contrail-vrouter-dpdk' with pid 161586 <<<<
2018-04-10 13:57:11,379 INFO success: contrail-vrouter-dpdk entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2018-04-10 13:57:18,768 INFO exited: contrail-vrouter-agent (terminated by SIGABRT (core dumped); not expected)
2018-04-10 13:57:19,771 INFO spawned: 'contrail-vrouter-agent' with pid 162067
2018-04-10 13:57:24,890 INFO success: contrail-vrouter-agent entered RUNNING state, process has stayed up for > than 5 seconds (startsecs)

contrail-vrouter-nodemgr-stderr.log:

04/10/2018 01:57:04 PM [contrail-vrouter-nodemgr]: send_process_state_db_base: Sending UVE:NodeStatusUVE(_context='', _scope='', _category='', _send_queue_enabled=True, _seqnum=0, _versionsig=2524127670, _source='mtn6r03c005.mtn6.cci.att.com', _instance_id='0', _client=None, _type=6, _hints=1, _http_server=None, _logger=None, _more=False, _node_type='Compute', data=NodeStatus(status=None, name='mtn6r03c005.mtn6.cci.att.com', installed_package_version=None, deleted=False, disk_usage_info=None, build_info='{"build-info" : [{"build-version" : "3.2.9.0", "build-time" : "2018-03-04 18:32:39.154612", "build-user" : "contrail-builder", "build-hostname" : "ubuntu", "build-id" : "3.2.9.0-69", "build-number" : "69"}]}', running_package_version=None, process_mem_cpu_usage=None, system_cpu_info=None, system_mem_usage=None, process_status=None, all_core_file_list=None, system_cpu_usage=None, _table='ObjectVRouter', process_info=[ProcessInfo(process_name='contrail-vrouter-agent', process_state='PROCESS_STATE_RUNNING', last_stop_time='1522357532760184', start_count=87, core_file_list=[], last_start_time='1522357538691673', stop_count=1, last_exit_time='1522101847329315', exit_count=85), ProcessInfo(process_name='contrail-vrouter-nodemgr', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=2, core_file_list=[], last_start_time='1522063518471970', stop_count=0, last_exit_time='', exit_count=0), ProcessInfo(process_name='contrail-vrouter-dpdk', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=2, core_file_list=[], last_start_time='1522063518476043', stop_count=0, last_exit_time='', exit_count=0)], description=None), _module='contrail-vrouter-nodemgr', _level=2147483647, _timestamp=1523368624647209, _client_context='', _connect_to_collector=True, _role=0)

04/10/2018 01:57:04 PM [contrail-vrouter-nodemgr]: Sandesh Send Level [INVALID] -> [SYS_DEBUG]
04/10/2018 01:57:04 PM [contrail-vrouter-nodemgr]: Sandesh Send Level [SYS_DEBUG] -> [INVALID]
wokeup and found a line
contrail-vrouter-dpdk with pid:6886 exited abnormally
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
find command option for cores:find /var/crashes
 -name core.[A-Za-z]*.6886*
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
core file: /var/crashes/core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617

core_file_list:[], self.max_cores:4
# of cores for contrail-vrouter-dpdk:1
04/10/2018 01:57:10 PM [contrail-vrouter-nodemgr]: send_process_state_db_base: Sending UVE:NodeStatusUVE(_context='', _scope='', _category='', _send_queue_enabled=True, _seqnum=0, _versionsig=2524127670, _source='mtn6r03c005.mtn6.cci.att.com', _instance_id='0', _client=None, _type=6, _hints=1, _http_server=None, _logger=None, _more=False, _node_type='Compute', data=NodeStatus(status=None, name='mtn6r03c005.mtn6.cci.att.com', installed_package_version=None, deleted=False, disk_usage_info=None, build_info='{"build-info" : [{"build-version" : "3.2.9.0", "build-time" : "2018-03-04 18:32:39.154612", "build-user" : "contrail-builder", "build-hostname" : "ubuntu", "build-id" : "3.2.9.0-69", "build-number" : "69"}]}', running_package_version=None, process_mem_cpu_usage=None, system_cpu_info=None, system_mem_usage=None, process_status=None, all_core_file_list=None, system_cpu_usage=None, _table='ObjectVRouter', process_info=[ProcessInfo(process_name='contrail-vrouter-agent', process_state='PROCESS_STATE_RUNNING', last_stop_time='1522357532760184', start_count=87, core_file_list=[], last_start_time='1522357538691673', stop_count=1, last_exit_time='1522101847329315', exit_count=85), ProcessInfo(process_name='contrail-vrouter-nodemgr', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=2, core_file_list=[], last_start_time='1522063518471970', stop_count=0, last_exit_time='', exit_count=0), ProcessInfo(process_name='contrail-vrouter-dpdk', process_state='PROCESS_STATE_EXITED', last_stop_time='', start_count=2, core_file_list=['/var/crashes/core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617'], last_start_time='1522063518476043', stop_count=0, last_exit_time='1523368630020617', exit_count=1)], description=None), _module='contrail-vrouter-nodemgr', _level=2147483647, _timestamp=1523368630033609, _client_context='', _connect_to_collector=True, _role=0)
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
contrail is not in the sudoers file. This incident will be reported.
04/10/2018 01:57:10 PM [contrail-vrouter-nodemgr]: Execution of action sudo service contrail-vrouter-agent stop returned err 1
wokeup and found a line
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
contrail is not in the sudoers file. This incident will be reported.
04/10/2018 01:57:10 PM [contrail-vrouter-nodemgr]: Execution of action sudo service contrail-vrouter-agent restart returned err 1
wokeup and found a line
04/10/2018 01:57:12 PM [contrail-vrouter-nodemgr]: send_process_state_db_base: Sending UVE:NodeStatusUVE(_context='', _scope='', _category='', _send_queue_enabled=True, _seqnum=0, _versionsig=2524127670, _source='mtn6r03c005.mtn6.cci.att.com', _instance_id='0', _client=None, _type=6, _hints=1, _http_server=None, _logger=None, _more=False, _node_type='Compute', data=NodeStatus(status=None, name='mtn6r03c005.mtn6.cci.att.com', installed_package_version=None, deleted=False, disk_usage_info=None, build_info='{"build-info" : [{"build-version" : "3.2.9.0", "build-time" : "2018-03-04 18:32:39.154612", "build-user" : "contrail-builder", "build-hostname" : "ubuntu", "build-id" : "3.2.9.0-69", "build-number" : "69"}]}', running_package_version=None, process_mem_cpu_usage=None, system_cpu_info=None, system_mem_usage=None, process_status=None, all_core_file_list=None, system_cpu_usage=None, _table='ObjectVRouter', process_info=[ProcessInfo(process_name='contrail-vrouter-agent', process_state='PROCESS_STATE_RUNNING', last_stop_time='1522357532760184', start_count=87, core_file_list=[], last_start_time='1522357538691673', stop_count=1, last_exit_time='1522101847329315', exit_count=85), ProcessInfo(process_name='contrail-vrouter-nodemgr', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=2, core_file_list=[], last_start_time='1522063518471970', stop_count=0, last_exit_time='', exit_count=0), ProcessInfo(process_name='contrail-vrouter-dpdk', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=3, core_file_list=['/var/crashes/core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617'], last_start_time='1523368632381540', stop_count=0, last_exit_time='1523368630020617', exit_count=1)], description=None), _module='contrail-vrouter-nodemgr', _level=2147483647, _timestamp=1523368632381905, _client_context='', _connect_to_collector=True, _role=0)
wokeup and found a line
contrail-vrouter-agent with pid:80654 exited abnormally
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
find command option for cores:find /var/crashes
 -name core.[A-Za-z]*.80654*
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
core file: /var/crashes/core.contrail-vroute.80654.mtn6r03c005.mtn6.cci.att.com.1523368630

core_file_list:[], self.max_cores:4
# of cores for contrail-vrouter-agent:1
04/10/2018 01:57:19 PM [contrail-vrouter-nodemgr]: send_process_state_db_base: Sending UVE:NodeStatusUVE(_context='', _scope='', _category='', _send_queue_enabled=True, _seqnum=0, _versionsig=2524127670, _source='mtn6r03c005.mtn6.cci.att.com', _instance_id='0', _client=None, _type=6, _hints=1, _http_server=None, _logger=None, _more=False, _node_type='Compute', data=NodeStatus(status=None, name='mtn6r03c005.mtn6.cci.att.com', installed_package_version=None, deleted=False, disk_usage_info=None, build_info='{"build-info" : [{"build-version" : "3.2.9.0", "build-time" : "2018-03-04 18:32:39.154612", "build-user" : "contrail-builder", "build-hostname" : "ubuntu", "build-id" : "3.2.9.0-69", "build-number" : "69"}]}', running_package_version=None, process_mem_cpu_usage=None, system_cpu_info=None, system_mem_usage=None, process_status=None, all_core_file_list=None, system_cpu_usage=None, _table='ObjectVRouter', process_info=[ProcessInfo(process_name='contrail-vrouter-agent', process_state='PROCESS_STATE_EXITED', last_stop_time='1522357532760184', start_count=87, core_file_list=['/var/crashes/core.contrail-vroute.80654.mtn6r03c005.mtn6.cci.att.com.1523368630'], last_start_time='1522357538691673', stop_count=1, last_exit_time='1523368639772928', exit_count=86), ProcessInfo(process_name='contrail-vrouter-nodemgr', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=2, core_file_list=[], last_start_time='1522063518471970', stop_count=0, last_exit_time='', exit_count=0), ProcessInfo(process_name='contrail-vrouter-dpdk', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=3, core_file_list=['/var/crashes/core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617'], last_start_time='1523368632381540', stop_count=0, last_exit_time='1523368630020617', exit_count=1)], description=None), _module='contrail-vrouter-nodemgr', _level=2147483647, _timestamp=1523368639784971, _client_context='', _connect_to_collector=True, _role=0)
wokeup and found a line
wokeup and found a line
04/10/2018 01:57:25 PM [contrail-vrouter-nodemgr]: send_process_state_db_base: Sending UVE:NodeStatusUVE(_context='', _scope='', _category='', _send_queue_enabled=True, _seqnum=0, _versionsig=2524127670, _source='mtn6r03c005.mtn6.cci.att.com', _instance_id='0', _client=None, _type=6, _hints=1, _http_server=None, _logger=None, _more=False, _node_type='Compute', data=NodeStatus(status=None, name='mtn6r03c005.mtn6.cci.att.com', installed_package_version=None, deleted=False, disk_usage_info=None, build_info='{"build-info" : [{"build-version" : "3.2.9.0", "build-time" : "2018-03-04 18:32:39.154612", "build-user" : "contrail-builder", "build-hostname" : "ubuntu", "build-id" : "3.2.9.0-69", "build-number" : "69"}]}', running_package_version=None, process_mem_cpu_usage=None, system_cpu_info=None, system_mem_usage=None, process_status=None, all_core_file_list=None, system_cpu_usage=None, _table='ObjectVRouter', process_info=[ProcessInfo(process_name='contrail-vrouter-agent', process_state='PROCESS_STATE_RUNNING', last_stop_time='1522357532760184', start_count=88, core_file_list=['/var/crashes/core.contrail-vroute.80654.mtn6r03c005.mtn6.cci.att.com.1523368630'], last_start_time='1523368645891931', stop_count=1, last_exit_time='1523368639772928', exit_count=86), ProcessInfo(process_name='contrail-vrouter-nodemgr', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=2, core_file_list=[], last_start_time='1522063518471970', stop_count=0, last_exit_time='', exit_count=0), ProcessInfo(process_name='contrail-vrouter-dpdk', process_state='PROCESS_STATE_RUNNING', last_stop_time='', start_count=3, core_file_list=['/var/crashes/core.lcore-slave-9.6886.mtn6r03c005.mtn6.cci.att.com.1523368617'], last_start_time='1523368632381540', stop_count=0, last_exit_time='1523368630020617', exit_count=1)], description=None), _module='contrail-vrouter-nodemgr', _level=2147483647, _timestamp=1523368645893566, _client_context='', _connect_to_collector=True, _role=0)

contrail-vrouter-dpdk-stdout.log:

...
2018-04-10 13:47:30,872 UVHOST: Client _tap374a1fc8-f6: vring 1 is ready
2018-04-10 13:47:30,872 UVHOST: Client _tap374a1fc8-f6: no handler defined for message 12
2018-04-10 13:51:55,460 UVHOST: Client _tap35caf2ed-8a: handling message 13
2018-04-10 13:51:55,460 UVHOST: SET VRING CALL: vring 0 FD 249
2018-04-10 13:51:55,460 UVHOST: Client _tap35caf2ed-8a: handling message 13
2018-04-10 13:51:55,460 UVHOST: SET VRING CALL: vring 0 FD 250
2018-04-10 13:51:59,458 UVHOST: Client _tap374a1fc8-f6: handling message 13
2018-04-10 13:51:59,458 UVHOST: SET VRING CALL: vring 0 FD 249
2018-04-10 13:51:59,472 UVHOST: Client _tap374a1fc8-f6: handling message 13
2018-04-10 13:51:59,472 UVHOST: SET VRING CALL: vring 0 FD 251
2018-04-10 13:57:10,030 VROUTER: vRouter/DPDK version: {"build-info": [{"build-time": "2018-03-04 18:54:00.499936", "build-hostname": "ubuntu", "build-user": "contrail-builder", "build-version": "3.2.9.0"}]}
2018-04-10 13:57:10,082 VROUTER: Max HOLD flow entries set to 1000
2018-04-10 13:57:10,083 VROUTER: Using VLAN TCI: 2004
2018-04-10 13:57:10,083 VROUTER: Bridge Table limit: 262144
2018-04-10 13:57:10,083 VROUTER: Bridge Table overflow limit: 0
2018-04-10 13:57:10,083 VROUTER: Flow Table limit: 2097152
2018-04-10 13:57:10,083 VROUTER: Flow Table overflow limit: 419840
2018-04-10 13:57:10,083 VROUTER: MPLS labels limit: 6000
2018-04-10 13:57:10,083 VROUTER: Nexthops limit: 65536
2018-04-10 13:57:10,083 VROUTER: VRF tables limit: 4096
2018-04-10 13:57:10,083 VROUTER: Packet pool size: 16384
2018-04-10 13:57:10,083 VROUTER: Maximum packet size: 9216
2018-04-10 13:57:10,083 VROUTER: EAL arguments:
2018-04-10 13:57:10,083 VROUTER: -n "4"
2018-04-10 13:57:10,083 VROUTER: --socket-mem "1024,1024"
2018-04-10 13:57:10,083 VROUTER: --vdev "eth_bond_bond0,mode=4,xmit_policy=l34,socket_id=1,mac=00:11:ac:1d:d9:2f,slave=0000:83:00.1,slave=0000:03:00.0"
2018-04-10 13:57:10,083 VROUTER: --lcores "(0-2)@(0-55),(8-9)@(0-55),10@2,11@3,12@4,13@5,14@30,15@31,16@32,17@33"
2018-04-10 13:57:10,083 EAL: Detected 56 lcore(s)
2018-04-10 13:57:10,098 EAL: Probing VFIO support...
2018-04-10 13:57:58,333 EAL: PCI device 0000:01:00.0 on NUMA socket 0
2018-04-10 13:57:58,333 EAL: probe driver: 8086:10fb net_ixgbe
2018-04-10 13:57:58,333 EAL: PCI device 0000:01:00.1 on NUMA socket 0
2018-04-10 13:57:58,333 EAL: probe driver: 8086:10fb net_ixgbe
2018-04-10 13:57:58,333 EAL: PCI device 0000:03:00.0 on NUMA socket 0
2018-04-10 13:57:58,333 EAL: probe driver: 8086:154d net_ixgbe
2018-04-10 13:57:58,472 EAL: PCI device 0000:03:00.1 on NUMA socket 0
2018-04-10 13:57:58,472 EAL: probe driver: 8086:154d net_ixgbe
2018-04-10 13:57:58,472 EAL: PCI device 0000:06:00.0 on NUMA socket 0
2018-04-10 13:57:58,472 EAL: probe driver: 8086:1521 net_e1000_igb
2018-04-10 13:57:58,472 EAL: PCI device 0000:06:00.1 on NUMA socket 0
2018-04-10 13:57:58,472 EAL: probe driver: 8086:1521 net_e1000_igb
2018-04-10 13:57:58,472 EAL: PCI device 0000:83:00.0 on NUMA socket 1
2018-04-10 13:57:58,472 EAL: probe driver: 8086:154d net_ixgbe
2018-04-10 13:57:58,472 EAL: PCI device 0000:83:00.1 on NUMA socket 1
2018-04-10 13:57:58,472 EAL: probe driver: 8086:154d net_ixgbe
2018-04-10 13:57:58,612 EAL: Initializing pmd_bond for eth_bond_bond0
2018-04-10 13:57:58,612 PMD: Using mode 4, it is necessary to do TX burst and RX burst at least every 100ms.
2018-04-10 13:57:58,612 EAL: Create bonded device eth_bond_bond0 on port 2 in mode 4 on socket 1.
2018-04-10 13:57:58,638 VROUTER: Found 3 eth device(s)
2018-04-10 13:57:58,638 VROUTER: Using 8 forwarding lcore(s)
2018-04-10 13:57:58,638 VROUTER: Using 0 IO lcore(s)
2018-04-10 13:57:58,638 VROUTER: Using 5 service lcores
2018-04-10 13:57:58,638 VROUTER: set fd limit to 4096 (prev 1024, max 4096)
2018-04-10 13:57:58,670 VROUTER: Adding VLAN forwarding interface bond0
2018-04-10 13:57:58,670 VROUTER: initializing KNI with 16 maximum interfaces
2018-04-10 13:57:58,671 VROUTER: bind KNI kernel thread to CPU 8
2018-04-10 13:57:58,672 KNI: pci: 03:00:00 8086:154d
2018-04-10 13:57:58,672 VROUTER: Starting NetLink...
2018-04-10 13:57:58,672 VROUTER: Lcore 14: distributing MPLSoGRE packets to [10,11,12,13,15,16,17]
2018-04-10 13:57:58,672 VROUTER: Lcore 10: distributing MPLSoGRE packets to [10,11,12,13,14,15,16]
2018-04-10 13:57:58,672 VROUTER: Lcore 13: distributing MPLSoGRE packets to [10,11,12,13,14,15,16]
2018-04-10 13:57:58,672 USOCK: usock_alloc[7f80039e3700]: new socket FD 62
2018-04-10 13:57:58,672 USOCK: usock_alloc[7f80039e3700]: setting socket FD 62 nodelay.
2018-04-10 13:57:58,672 VROUTER: Lcore 16: distributing MPLSoGRE packets to [10,11,12,13,14,15,16]
2018-04-10 13:57:58,672 VROUTER: Lcore 11: distributing MPLSoGRE packets to [10,11,12,13,14,15,16]
2018-04-10 13:57:58,672 VROUTER: Lcore 17: distributing MPLSoGRE packets to [10,11,12,13,14,15,16]
2018-04-10 13:57:58,672 USOCK: usock_alloc[7f80039e3700]: setting socket FD 62 send buff size.
Buffer size set to 18320000 (requested 9216000)
2018-04-10 13:57:58,672 VROUTER: Lcore 12: distributing MPLSoGRE packets to [10,11,12,13,14,15,16]
2018-04-10 13:57:58,672 VROUTER: Lcore 15: distributing MPLSoGRE packets to [10,11,12,13,14,15,16]
2018-04-10 13:57:58,672 VROUTER: NetLink TCP socket FD is 62
2018-04-10 13:57:58,672 VROUTER: uvhost Unix socket FD is 63
2018-04-10 13:57:58,674 UVHOST: Starting uvhost server...
2018-04-10 13:57:58,674 UVHOST: server event FD is 64
2018-04-10 13:57:58,674 UVHOST: server socket FD is 65
2018-04-10 13:57:59,673 VROUTER: Retrying connection for socket 63...
2018-04-10 13:57:59,673 UVHOST: Handling connection FD 65...
2018-04-10 13:57:59,673 UVHOST: FD 65 accepted new NetLink connection FD 66
2018-04-10 13:57:59,673 DPCORE: vrouter soft reset start
2018-04-10 13:57:59,709 DPCORE: vrouter soft reset done (0)
2018-04-10 13:58:01,862 VROUTER: Adding vif 0 (gen. 1) eth device 2 PCI 0000:00:00.0 MAC 00:00:00:00:00:00 (vif MAC 00:11:ac:1d:d9:2f)
2018-04-10 13:58:01,862 VROUTER: Using 10 TX queues, 8 RX queues
2018-04-10 13:58:01,862 VROUTER: bond eth device 2 configured MAC 00:11:ac:1d:d9:2f
2018-04-10 13:58:01,862 VROUTER: bond member eth device 1 PCI 0000:83:00.1 MAC a0:36:9f:c1:99:76
2018-04-10 13:58:01,862 VROUTER: bond member eth device 1 promisc mode disabled
2018-04-10 13:58:01,862 VROUTER: bond member eth device 0 PCI 0000:03:00.0 MAC a0:36:9f:c0:0f:70
2018-04-10 13:58:01,862 VROUTER: bond member eth device 0 promisc mode disabled
2018-04-10 13:58:01,862 VROUTER: setup 8 RSS queue(s) and 0 filtering queue(s)
2018-04-10 13:58:02,037 PMD: ixgbe_dev_link_status_print(): Port 1: Link Up - speed 0 Mbps - half-duplex
2018-04-10 13:58:02,212 PMD: ixgbe_dev_link_status_print(): Port 0: Link Up - speed 0 Mbps - half-duplex
2018-04-10 13:58:02,212 VROUTER: lcore 10 TX to HW queue 0
2018-04-10 13:58:02,212 VROUTER: lcore 11 TX to HW queue 1
2018-04-10 13:58:02,212 VROUTER: lcore 12 TX to HW queue 2
2018-04-10 13:58:02,212 VROUTER: lcore 13 TX to HW queue 3
2018-04-10 13:58:02,212 VROUTER: lcore 14 TX to HW queue 4
2018-04-10 13:58:02,212 VROUTER: lcore 15 TX to HW queue 5
2018-04-10 13:58:02,212 VROUTER: lcore 16 TX to HW queue 6
2018-04-10 13:58:02,212 VROUTER: lcore 17 TX to HW queue 7
2018-04-10 13:58:02,212 VROUTER: lcore 8 TX to HW queue 8
2018-04-10 13:58:02,212 VROUTER: lcore 9 TX to HW queue 9
2018-04-10 13:58:02,212 VROUTER: lcore 10 RX from HW queue 0
2018-04-10 13:58:02,212 VROUTER: lcore 11 RX from HW queue 1
2018-04-10 13:58:02,212 VROUTER: lcore 12 RX from HW queue 2
2018-04-10 13:58:02,212 VROUTER: lcore 13 RX from HW queue 3
2018-04-10 13:58:02,212 VROUTER: lcore 14 RX from HW queue 4
2018-04-10 13:58:02,212 VROUTER: lcore 15 RX from HW queue 5
2018-04-10 13:58:02,212 VROUTER: lcore 16 RX from HW queue 6
2018-04-10 13:58:02,212 VROUTER: lcore 17 RX from HW queue 7
...