Article Detail

Description

Customers may fine tune CPU pinning settings anytime to test best performance. However, when an issue is reported, it might be useful to get the historical CPU pinning settings of the moment when the issue occurred rather than the "current" setting, and this information is available in a log file.

In this article, we describe how to interpret the historical CPU pinning information of a dpdk vrouter in the log file.

Note: KB36056 - [Contrail] How to locate DPDK vrouter threads using Linux command line [juniper.net] explains the roles of different threads in dpdk-vrouter and KB35517 - [Contrail] Understanding CPU pinning in DPDK configuration [juniper.net] explains how CPU pinning works with examples.

Symptoms

Tracking pinning information may be useful in some cases. For example, a customer changes CPU pinning settings and later encounters an issue. By the time, the Support team requests previous CPU pinning information for comparison purposes, the old configuration before the change may not be present any more. In this case, the logs can reveal the old information.

Solution

When a router boots up, it displays a message about the numbering of its logical cores. This information can be found in the contrail-vrouter-dpdk-stdout.log file.

     $ cat /var/log/contrail/contrail-vrouter-dpdk-stdout.log
     ......
     2019-09-27 11:09:58,126 VROUTER:  --socket-mem  "1024,1024"
     2019-09-27 11:09:58,126 VROUTER:        --vdev  "eth_bond_bond0,mode=4,xmit_policy=l34,socket_id=0,mac=5c:b9:01:8b:6f:3c,slave=0000:08:00.0,slave=0000:08:00.1"
2019-09-27 11:09:58,126 VROUTER:      --lcores  "(0-2)@(0-47),(8-9)@(0-47),10@0,11@1,12@2,13@3"
2019-09-27 11:09:58,126 EAL: Detected 48 lcore(s)

In the following output, the first two lines reflect a portion of the settings from the vrouter dpdk configuration file at the moment that this log was generated:

     $ cat /etc/contrail/supervisord_vrouter_files/contrail-vrouter-dpdk.ini
     [program:contrail-vrouter-dpdk]
     command=taskset 0xf /usr/bin/contrail-vrouter-dpdk --no-daemon --vdev "eth_bond_bond0,mode=4,xmit_policy=l34,socket_id=0,mac=5c:b9:01:8b:6f:3c,slave=0000:08:00.0,slave=0000:08:00.1" --vlan_tci "2004" --vlan_fwd_intf_name "bond0" --socket-mem 1024,1024

The third line does not look very straightforward but in fact, it is encoded CPU pinning information from the same configuration file.

The log is explained as follows:

The first part of the message "(0-2)@(0-N),(8-9)@(0-N)" is all about service threads. It is always the same because this internal CPU logical numbering is statically defined in the vrouter source code. N is the total number of CPUs available in the compute node. Here N is 48 since the physical server here has 48 logical cores.
The part of the message "10@0,11@1,12@2,13@3" gives the CPU pinning of the forwarding threads. Here, four logical cores are used for forwarding purposes and they are numbered from 10 to 13. They are mapped one by one onto the host CPUs 0, 1, 2, and 3.

An example of a new vrouter configuration in the same compute is given as follows:

    $ cat /etc/contrail/supervisord_vrouter_files/contrail-vrouter-dpdk.ini
    [program:contrail-vrouter-dpdk]
    command=taskset -c 1,25,2,26,13,37,14,38 /usr/bin/contrail-vrouter-dpdk --no-daemon --vdev "eth_bond_bond0,mode=4,xmit_policy=l34,socket_id=1,mac=14:02:ec:66:b8:dc,slave=0000:87:00.0,slave=0000:09:00.1" --vlan_tci "722" --vlan_fwd_intf_name "bond0" --socket-mem 1024,1024

The above CPU pinning may trigger new logs similar to the following log capture:

     2020-04-23 11:11:01,996 VROUTER:  --socket-mem  "1024,1024"
     2020-04-23 11:11:01,996 VROUTER:        --vdev  "eth_bond_bond0,mode=4,xmit_policy=l34,socket_id=1,mac=14:02:ec:66:b8:dc,slave=0000:87:00.0,slave=0000:09:00.1"
2020-04-23 11:11:01,996 VROUTER:      --lcores  "(0-2)@(0-47),(8-9)@(0-47),10@1,11@2,12@13,13@14,14@25,15@26,16@37,17@38"
2020-04-23 11:11:01,997 EAL: Detected 48 lcore(s)