search

OpenFastPath / ofp

OpenFastPath project
BSD 3-Clause "New" or "Revised" License
351 stars 126 forks source link

pktio failure when running example #207

Closed bestgen closed 6 years ago

bestgen commented 6 years ago

Hello. The threads got stuck in executing ofp_rt_rule_remove() function in ofp_udp_usrreq.c when I try to run the webserver examples.

Here are the strace results:

mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0I 0 0:616875776 ofp_cli.c:1599] CLI server started on core 0

) = 0x7fc023c4b000
mprotect(0x7fc023c4b000, 4096, PROT_NONE) = 0
clone(child_stack=0x7fc02444adf0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7fc02444b9d0, tls=0x7fc02444b700, child_tidptr=0x7fc02444b9d0) = 45060
sched_setaffinity(45060, 128, [0])      = 0
futex(0x7fc025c4e9d0, FUTEX_WAIT, 45057, NULLI 0 0:608483072 httpd.c:152] HTTP thread started
CONFIGURATION LINE: debug 0

CONFIGURATION LINE: loglevel set error

CONFIGURATION LINE: ifconfig fp0 10.0.0.10/24

) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=45062, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
futex(0x7fc025c4e9d0, FUTEX_WAIT, 45057, NULL
W 43 0:642053888 ofp_rt_mtrie_lookup.c:516] ofp_rtl_remove no rule found for vrf 0 addr 0.0.0.10 masklen 8
E 43 0:642053888 ofp_rt_mtrie_lookup.c:276] ofp_rt_rule_remove rule vrf 0 10.0.0.0/8 not exist
W 66 2:633661184 ofp_udp_usrreq.c:575] badunlocked
W 167 2:633661184 ofp_udp_usrreq.c:575] badunlocked
W 369 3:625268480 ofp_udp_usrreq.c:575] badunlocked
W 758 3:625268480 ofp_udp_usrreq.c:575] badunlocked
W 1573 3:625268480 ofp_udp_usrreq.c:575] badunlocked
odp_timer.c:681:timer_notify():
    1 ticks overrun on timer pool "TmrPool", timer resolution too high
W 6371 2:633661184 ofp_udp_usrreq.c:575] badunlocked
W 25528 3:625268480 ofp_udp_usrreq.c:575] badunlocked
W 51134 3:625268480 ofp_udp_usrreq.c:575] badunlocked
) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
futex(0x7fc025c4e9d0, FUTEX_WAIT, 45057, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGWINCH {si_signo=SIGWINCH, si_code=SI_KERNEL} ---
futex(0x7fc025c4e9d0, FUTEX_WAIT, 45057, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)

First it was stuck in showing badunlocked for a few minutes, then it turned to show trying to restart.

Can someone please offer a little help? Thanks.

BTW: The guide "Start the application with command like: ./example/webserver/webserver -i ens1f0 -c 4 -f ./example/webserver/ofp.cli & should be changed into : ./example/webserver/webserver -i ens1f0 -c 4 -f ./example/webserver/ofp.conf & in the user-guide https://github.com/OpenFastPath/ofp/blob/master/docs/ofp-user-guide.adoc#starting-an-example-application as the file name has been updated.

bestgen commented 6 years ago

The result of debug shows that the sentence: socket_mmap.c --> map_pkt_socket(void) -->int ret, sock = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL)); seems failed to execute, as it failed to enter int socket() in netwrap_socket.c , and then it turn to enter : 

if (sock == -1) {
        __odp_errno = errno;
        ODP_ERR("socket(SOCK_RAW): %s\n", strerror(errno));
        return -1;
    }

and shows: pktio/socket_mmap.c:78:mmap_pkt_socket():socket(SOCK_RAW): Operation not permitted.

There is another similar error in socket.c. pktio/socket.c:509:sock_setup_pkt():socket(): Operation not permitted.

then the program turn to odp_packet_io.c and shows: odp_packet_io.c:224:setup_pktio_entry():Unable to init any I/O type. ofp_ifnet.c:23] odp_pktio_open failed.

Could you give some suggestion about the pktio failure? I met nearly the same problems when I run other examples of ofp, such as fpm.

Thank you very much in advance.

bogdanPricope commented 6 years ago

Do not link your application/ofp example applications with libofp_netwrap_crt.so/.a or libofp_netwrap_proc.so/.a. You will not need them for regular ofp applications (like webserver / webserver2)

Those libs are to be used with LD_PRELOAD in a particular usecase. See https://github.com/OpenFastPath/ofp/blob/master/scripts/ofp_netwrap.sh.

bestgen commented 6 years ago

Thank you @bogdanPricope . I followed your advice but it turns to get stuck in failing to bind http socket. 

futex(0x7f13be8c19d0, FUTEX_WAIT, 3032, NULLI 0 0:3171673856 httpd.c:152] HTTP thread started
I 0 0:3180066560 ofp_cli.c:1599] CLI server started on core 0
E 107 0:3171673856 httpd.c:176] Cannot bind http socket (Can't assign requested address)!

The error can be located at the codes (in case needed): 

static void *webserver(void *arg)
{
int serv_fd, tmp_fd, nfds;
    unsigned int alen;
    struct ofp_sockaddr_in my_addr, caller;
    ofp_fd_set read_fd;

    (void)arg;

    OFP_INFO("HTTP thread started");

    if (ofp_init_local()) {
        OFP_ERR("Error: OFP local init failed.\n");
        return NULL;
    }
    sleep(1);

    myaddr = ofp_port_get_ipv4_addr(0, 0, OFP_PORTCONF_IP_TYPE_IP_ADDR);

    if ((serv_fd = ofp_socket(OFP_AF_INET, OFP_SOCK_STREAM, OFP_IPPROTO_TCP)) < 0) {
        OFP_ERR("ofp_socket failed");
        perror("serv socket");
        return NULL;
    }

    memset(&my_addr, 0, sizeof(my_addr));
    my_addr.sin_family = OFP_AF_INET;
    my_addr.sin_port = odp_cpu_to_be_16(2048);
    my_addr.sin_addr.s_addr = myaddr;
    my_addr.sin_len = sizeof(my_addr);

    **if (ofp_bind(serv_fd, (struct ofp_sockaddr *)&my_addr,
               sizeof(struct ofp_sockaddr)) < 0) {
        OFP_ERR("Cannot bind http socket (%s)!", ofp_strerror(ofp_errno));
        return 0;
    }**

and ofp_bind() is :

ofp_bind(int sockfd, const struct ofp_sockaddr *addr, ofp_socklen_t addrlen)
{
    struct thread   td;
    union ofp_sockaddr_store nonconstaddr;
    struct socket  *so = ofp_get_sock_by_fd(sockfd);

    if (!so) {
        ofp_errno = OFP_EBADF;
        return -1;
    }

    memcpy(&nonconstaddr, addr, addrlen);

    td.td_proc.p_fibnum = so->so_fibnum;
    td.td_ucred = NULL;
    ofp_errno = ofp_sobind(so, (struct ofp_sockaddr *)&nonconstaddr,
        &td);
    return ofp_errno ? -1 : 0;
}

Thanks.

bogdanPricope commented 6 years ago

This is because you don't have the IP address set on first (and only) interface : meaning using ofp.cli file: e.g. ./example/webserver/webserver -i ens1f0 -c 4 -f ./example/webserver/ofp.cli

There are two kind of "configuration" files: *.cli files - are actually a batch of CLI command debug 0 loglevel set debug ifconfig fp0 192.168.56.33/24

*.conf files - are OFP settings - are used to override default settings, configure staff, etc. ofp_global_param: { if_names = ("eth1") linux_core_id = 0 pktin_mode = "sched" pktout_mode = "direct" sched_sync = "atomic" sched_group = "all" enable_nl_thread = false arp: { entry_timeout = 1200 check_interface = false } evt_rx_burst_size = 16 pkt_tx_burst_size = 16 pcb_tcp_max = 60000 pkt_pool: { nb_pkts = 10240 buffer_size = 1856 } };

You will probably not need .conf file for your test but I am putting below how can be used: OFP_CONF_FILE=./ofp_init.conf ./example/webserver/webserver -i ens1f0 -c 4 -f ./example/webserver/ofp.cli

This is specially confusing since we initially named .cli files as .conf.

So, use cli file in your test to have an address on the interface - so you can ofp_bind(), etc.

bogdanPricope commented 6 years ago

If you are sure you are using the correct CLI file, then it might be a bug: webserver thread is started before CLI thread was able to set the IP address. There is a "non-elegant" sleep(1) in webserver() to prevent this but it might not be enough.

bestgen commented 6 years ago

Hello @bogdanPricope . Sorry to bother you again, but after I remove the libofp_netwrap links, the webserver example still got the same problem. The werbserver application still stuck in running ofp_rt_rule_add or odp_timer. 

Setting to max: 0
 PKTIO: initialized loop interface.
 PKTIO: initialized pcap interface.
 PKTIO: initialized socket mmap, use export ODP_PKTIO_DISABLE_SOCKET_MMAP=1 to disable.
 PKTIO: initialized socket mmsg,use export ODP_PKTIO_DISABLE_SOCKET_MMSG=1 to disable.

ODP system info
---------------
ODP API version: 1.11.0
CPU model:       Intel(R) Core(TM) i7-6700 CPU
CPU freq (hz):   3407874000
Cache line size: 64
Core count:      4

Running ODP appl: "webserver"
-----------------
IF-count:        1
Using IFs:       ens33

Num worker threads: 2
first CPU:          2
cpu mask:           0xC
I 1 3:1015789824 ofp_uma.c:44] Creating pool 'udp_inpcb', nitems=1024 size=904 total=925696
I 1 3:1015789824 ofp_uma.c:44] Creating pool 'tcp_inpcb', nitems=2048 size=904 total=1851392
I 2 3:1015789824 ofp_uma.c:44] Creating pool 'tcpcb', nitems=2048 size=784 total=1605632
I 2 3:1015789824 ofp_uma.c:44] Creating pool 'tcptw', nitems=409 size=80 total=32720
I 2 3:1015789824 ofp_uma.c:44] Creating pool 'syncache', nitems=30720 size=168 total=5160960
I 2 3:1015789824 ofp_uma.c:44] Creating pool 'tcpreass', nitems=320 size=48 total=15360
I 2 3:1015789824 ofp_uma.c:44] Creating pool 'sackhole', nitems=65536 size=40 total=2621440
I 3 3:1015789824 ofp_init.c:191] Slow path threads on core 0
I 5 3:1015789824 ofp_ifnet.c:143] Device 'ens33' addr  00:0c:29:71:36:06
I 5 3:1015789824 ofp_ifnet.c:152] Device 'ens33' MTU=1500
I 0 0:822830848 ofp_cli.c:1599] CLI server started on core 0

CONFIGURATION LINE: debug 0
CONFIGURATION LINE: loglevel set debug
CONFIGURATION LINE: ifconfig fp0 192.168.56.33/24

I 6 0:822830848 ofp_rt_mtrie_lookup.c:267] ofp_rt_rule_add inserted new rule vrf 0 prefix 192.168.56.33/32
I 6 0:822830848 ofp_rt_mtrie_lookup.c:267] ofp_rt_rule_add inserted new rule vrf 0 prefix 192.168.56.0/24
I 0 0:814438144 httpd.c:152] HTTP thread started
I 6 0:848008960 ofp_rt_mtrie_lookup.c:239] ofp_rt_rule_add updated existing rule vrf 0 192.168.56.0/24

W 3390 2:839616256 ofp_udp_usrreq.c:575] badunlocked
W 3390 2:839616256 ofp_udp_usrreq.c:575] badunlocked
odp_timer.c:681:timer_notify():
    1 ticks overrun on timer pool "TmrPool", timer resolution too high

While if I slightly increase the sleep period in httpd.c file, then the ioctrl, tap allocation and ofp global initiation are all failed. 

I 1 1:1658693888 ofp_uma.c:44] Creating pool 'tcp_inpcb', nitems=2048 size=904 total=1851392
I 1 1:1658693888 ofp_uma.c:44] Creating pool 'tcpcb', nitems=2048 size=784 total=1605632
I 1 1:1658693888 ofp_uma.c:44] Creating pool 'tcptw', nitems=409 size=80 total=32720
I 1 1:1658693888 ofp_uma.c:44] Creating pool 'syncache', nitems=30720 size=168 total=5160960
I 3 1:1658693888 ofp_uma.c:44] Creating pool 'tcpreass', nitems=320 size=48 total=15360
I 3 1:1658693888 ofp_uma.c:44] Creating pool 'sackhole', nitems=65536 size=40 total=2621440
I 4 1:1658693888 ofp_init.c:191] Slow path threads on core 0
I 6 1:1658693888 ofp_ifnet.c:143] Device 'ens33' addr  00:0c:29:71:36:06
I 6 1:1658693888 ofp_ifnet.c:152] Device 'ens33' MTU=1500
E 6 1:1658693888 ofp_tunthread.c:60] ioctl failed
E 6 1:1658693888 ofp_tunthread.c:101] tap_alloc failed
E 6 1:1658693888 app_main.c:126] Error: OFP global init failed.
bogdanPricope commented 6 years ago

"ofp_rt_rule_add inserted new rule" are OFP INFO messages (not errors) "timer resolution too high" is an ODP warning message (should be OK) "ofp_udp_usrreq.c:575] badunlocked" - likely, you received an UDP packet for not existing UDP socket.

For first log, I can see only warnings - should work as far as I can tell. Second log: looks like a failure of creating SlowPath tap interface

BTW, why are you using such an old ODP version? - try to switch to v1.19.0.1_tigermoth tag. (meaning, not all ODP/OFP versions combinations were tested or it suppose to work)

bestgen commented 6 years ago

Thanks @bogdanPricope . I disable the slow path but the problem still exists. Threads and CLI can be started and the virtual interface f0 can be added, but the terminal cannot communicate though port 2345 when I try to open the web page. I do running as the super user and use strace to check the process, it shows that the problem appears in I/O control. 

bind(3, {sa_family=AF_PACKET, proto=0x03, if2, pkttype=PACKET_HOST, addr(0)={0, }, 20) = 0
setsockopt(3, SOL_PACKET, PACKET_TX_RING, {block_size=2097152, block_nr=4, frame_size=4096, frame_nr=2048}, 16) = 0
setsockopt(3, SOL_PACKET, PACKET_RX_RING, {block_size=2097152, block_nr=4, frame_size=4096, frame_nr=2048}, 16) = 0
mmap(NULL, 16777216, PROT_READ|PROT_WRITE, MAP_SHARED|MAP_POPULATE|MAP_LOCKED, 3, 0) = 0x7f9de5f38000
ioctl(3, SIOCGIFHWADDR, {ifr_name="ens33", ifr_hwaddr=00:0c:29:71:36:06}) = 0
socket(AF_LOCAL, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 4
ioctl(4, SIOCGIFINDEX, {ifr_name="ens33", }) = 0
close(4)                                = 0

setsockopt(3, SOL_PACKET, PACKET_FANOUT, [2], 4) = 0
ioctl(3, SIOCETHTOOL, 0x7fff3acd4780)   = -1 ENODEV (No such device)
open("/sys/class/net//statistics/rx_bytes", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/sys/class/net//statistics/rx_packets", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/sys/class/net//statistics/rx_droppped", O_RDONLY) = -1 ENOENT (No such file or directory)
.......( similar as the messages above ,not important).......
write(2, "I 14 1:4008933632 ofp_ifnet.c:14"..., 74I 14 1:4008933632 ofp_ifnet.c:143] Device 'ens33' addr  00:0c:29:71:36:06
) = 74
ioctl(3, SIOCGIFMTU, {ifr_name="ens33", ifr_mtu=1500}) = 0
write(2, "I 14 1:4008933632 ofp_ifnet.c:15"..., 59I 14 1:4008933632 ofp_ifnet.c:152] Device 'ens33' MTU=1500
) = 59
open("/dev/net/tun", O_RDWR)            = 4
ioctl(4, TUNSETIFF, 0x7fff3acd4990)     = -1 EBUSY (Device or resource busy)
write(2, "E 14 1:4008933632 ofp_tunthread."..., 51E 14 1:4008933632 ofp_tunthread.c:60] ioctl failed
) = 51
close(4)                                = 0
write(2, "E 14 1:4008933632 ofp_tunthread."..., 56E 14 1:4008933632 ofp_tunthread.c:101] tap_alloc failed
) = 56
write(2, "E 14 1:4008933632 app_main.c:189"..., 66E 14 1:4008933632 app_main.c:189] Error: OFP global init failed.

) = 66
exit_group(1)                           = ?
+++ exited with 1 +++

You see, the error appears after setsockopt(3, SOL_PACKET, PACKET_FANOUT, [2], 4) = 0. It seems to start another interface but failed, and then shows ioctl failed and OFP global init failed.

I turn to check ofptunthread.c and find it is the error of ioctl function, which is declared in the netwrap ioctl.c. I have removed all the .a/.so links related to libofp_netwrap. :

/* try to create the device */
    if( (err = ioctl(fd, TUNSETIFF, (void *) &ifr)) < 0 ) {
        OFP_ERR("ioctl failed");
        close(fd);
        return -1;
    }

Second, I tried to use some later version of ODP ,such as 1.19.0.1_tigermoth, v1.19.0.0, etc before, but all of them cannot work properly in my case, either. They even cannot allocate memory. ODP v1.11.0 and OFP 2.0.1 is the most possible version to work in my case...

bogdanPricope commented 6 years ago

  1. Disregard messages: open("/sys/class/net//statistics/rx_bytes", O_RDONLY) = -1 ENOENT (No such file or directory) ... This is ODP trying to determine support for some stats. I guess the result is STATS_UNSUPPORTED and should be fine...

  2. It seems slow path was NOT disabled (properly)

$ vim ./configure.ac ..................... AC_ARG_ENABLE([sp], [ --enable-sp Turn on Slow Path processing], [case "${enableval}" in yes) sp_support=true ;; no) sp_support=false ;; *) AC_MSG_ERROR([bad value ${enableval} for --enable-sp]) ;; esac],[sp_support=true]) AM_CONDITIONAL([OFP_SP], [test x$sp_support = xtrue]) ...........

$ vim ./src/Makefile.am ........................ if OFP_SP AM_CFLAGS += -DSP

LIBlibofp_la_SOURCES += \ ofp_netlink.c \ ofp_quagga.c \ ofp_tunthread.c endif .....................

Meaning, if slow path is disabled, you should not have ofp_tunthread.c built (and symbols in the lib). My guess is you either used your own build system (and is not equivalent) or you did not properly disabled slow path. Make sure you clean (make clean) the .o files before rebuild.

bogdanPricope commented 6 years ago

$ ./bootstrap $ ./configure --with-odp=/odp_inst --enable-sp=no $ make clean $ make

./example/webserver/webserver -i enp1s0f1 -f ./ofp.cli

RLIMIT_CORE: 0/-1 Setting to max: 0 PKTIO: initialized loop interface. PKTIO: initialized pcap interface. PKTIO: initialized socket mmap, use export ODP_PKTIO_DISABLE_SOCKET_MMAP=1 to disable. PKTIO: initialized socket mmsg,use export ODP_PKTIO_DISABLE_SOCKET_MMSG=1 to disable.

ODP system info

ODP API version: 1.11.0 CPU model: Intel(R) Core(TM) i5-2400 CPU CPU freq (hz): 1736435000 Cache line size: 64 Core count: 4

Running ODP appl: "webserver"

IF-count: 1 Using IFs: enp1s0f1

Num worker threads: 2 first CPU: 2 cpu mask: 0xC I 1 2:3269650688 ofp_uma.c:44] Creating pool 'udp_inpcb', nitems=1024 size=904 total=925696 I 1 2:3269650688 ofp_uma.c:44] Creating pool 'tcp_inpcb', nitems=2048 size=904 total=1851392 I 2 2:3269650688 ofp_uma.c:44] Creating pool 'tcpcb', nitems=2048 size=784 total=1605632 I 2 2:3269650688 ofp_uma.c:44] Creating pool 'tcptw', nitems=409 size=80 total=32720 I 2 2:3269650688 ofp_uma.c:44] Creating pool 'syncache', nitems=30720 size=168 total=5160960 I 2 2:3269650688 ofp_uma.c:44] Creating pool 'tcpreass', nitems=320 size=48 total=15360 I 2 2:3269650688 ofp_uma.c:44] Creating pool 'sackhole', nitems=65536 size=40 total=2621440 I 3 2:3269650688 ofp_init.c:191] Slow path threads on core 0 I 8 2:3269650688 ofp_ifnet.c:143] Device 'enp1s0f1' addr a0:36:9f:28:e2:57 I 8 2:3269650688 ofp_ifnet.c:152] Device 'enp1s0f1' MTU=1500 I 0 0:3106264832 ofp_cli.c:1599] CLI server started on core 0

CONFIGURATION LINE: debug 0

CONFIGURATION LINE: loglevel set error

CONFIGURATION LINE: ifconfig fp0 192.168.150.1/24

bestgen commented 6 years ago

Thank you @bogdanPricope . I got nearly the same output in the terminal as you did above and the codes did go well until there. I debug the codes and find it cannot continue to execute when it goes to ofp_solisten() which is in ofp_uipc_socket.c. The annotation says this function transits a socket from a non-listening state to a listening state.

In ofp_syscalls.c: 

ofp_bind(int sockfd, const struct ofp_sockaddr *addr, ofp_socklen_t addrlen)
{
    struct thread   td;
    union ofp_sockaddr_store nonconstaddr;
    struct socket  *so = ofp_get_sock_by_fd(sockfd);

    if (!so) {
        ofp_errno = OFP_EBADF;
        return -1;
    }

    memcpy(&nonconstaddr, addr, addrlen);

    td.td_proc.p_fibnum = so->so_fibnum;
    td.td_ucred = NULL;
    ofp_errno = ofp_sobind(so, (struct ofp_sockaddr *)&nonconstaddr,
        &td);
    return ofp_errno ? -1 : 0;
}
(Then it turns to ofp_sobind() and ofp_solisten() in  ofp_uipc_socket.c)

I think that is where the problem happens. In my case, the CLI threads can be opened, as I can access to port 2345 with telnet. HTTP threads seems able to be opened, too. But when I try to access the port 2048 with curl or wget to check the result, the connections are refused. Telnet cannot access to the port, either. So I suppose that the program stuck at opening the port. Do you have any idea about that and offer some suggestion please? Really appreciate.

bogdanPricope commented 6 years ago

"find it cannot continue to execute when it goes to ofp_solisten()" - this may be a real OFP bug and for this you need support from OFP team: @sovu , @JereLeppanen please take a look.

Else, you may

bestgen commented 6 years ago

Thank you @bogdanPricope. As you suggested, I enabled debug to get more log messages. When I debug the codes, it shows:

Running ODP appl: "webserver"
-----------------
IF-count:        1
Using IFs:       ens33

Num worker threads: 2
first CPU:          2
cpu mask:           0xC
I 2 1:4160612608 ofp_uma.c:44] Creating pool 'udp_inpcb', nitems=1024 size=904 total=925696
I 2 1:4160612608 ofp_uma.c:44] Creating pool 'tcp_inpcb', nitems=2048 size=904 total=1851392
I 2 1:4160612608 ofp_uma.c:44] Creating pool 'tcpcb', nitems=2048 size=784 total=1605632
I 2 1:4160612608 ofp_uma.c:44] Creating pool 'tcptw', nitems=409 size=80 total=32720
I 2 1:4160612608 ofp_uma.c:44] Creating pool 'syncache', nitems=30720 size=168 total=5160960
I 3 1:4160612608 ofp_uma.c:44] Creating pool 'tcpreass', nitems=320 size=48 total=15360
I 3 1:4160612608 ofp_uma.c:44] Creating pool 'sackhole', nitems=65536 size=40 total=2621440
I 3 1:4160612608 ofp_init.c:191] Slow path threads on core 0
odp_timer.c:681:timer_notify():
    158 ticks overrun on timer pool "TmrPool", timer resolution too high
D 4 1:4160612608 ofp_ifnet.c:225] Interface 'ens33' becomes 'fp0', port 0
I 11 1:4160612608 ofp_ifnet.c:143] Device 'ens33' addr  00:0c:29:71:36:06
I 11 1:4160612608 ofp_ifnet.c:152] Device 'ens33' MTU=1500
I 0 0:3994969856 ofp_cli.c:1599] CLI server started on core 0

CONFIGURATION LINE: debug 0

CONFIGURATION LINE: loglevel set debug

CONFIGURATION LINE: ifconfig fp0 192.168.56.33/24

D 15 0:3994969856 ofp_route.c:202] Adding route vrf=0 addr=192.168.56.33/32
I 17 0:3994969856 ofp_rt_mtrie_lookup.c:267] ofp_rt_rule_add inserted new rule vrf 0 prefix 192.168.56.33/32
D 18 0:3994969856 ofp_route.c:202] Adding route vrf=0 addr=192.168.56.0/24
I 0 0:3986577152 httpd.c:152] HTTP thread started
I 25 0:3994969856 ofp_rt_mtrie_lookup.c:267] ofp_rt_rule_add inserted new rule vrf 0 prefix 192.168.56.0/24

D 1009 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0800
D 1009 3:4003362560 ofp_pkt_processing.c:322] Device IP: 192.168.56.33, Packet Dest IP: 169.254.255.255
D 1009 3:4003362560 ofp_pkt_processing.c:369] nh is NULL, vrf=0 dest=fffffea9
D 1014 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0800
D 1014 3:4003362560 ofp_pkt_processing.c:322] Device IP: 192.168.56.33, Packet Dest IP: 192.168.120.144
D 1014 3:4003362560 ofp_pkt_processing.c:369] nh is NULL, vrf=0 dest=9078a8c0
D 1017 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0806
D 1018 3:4003362560 ofp_pkt_processing.c:518] Device IP: 192.168.56.33, Packet Dest IP: 192.168.120.144
D 1023 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0800
D 1023 3:4003362560 ofp_pkt_processing.c:322] Device IP: 192.168.56.33, Packet Dest IP: 192.168.120.144
D 1023 3:4003362560 ofp_pkt_processing.c:369] nh is NULL, vrf=0 dest=9078a8c0
D 1028 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0806
D 1028 3:4003362560 ofp_route.c:113] Adding MAC= 00:50:56:e7:56:0a IP=192.168.120.254 on device port=0 vlan=0 vrf=0
D 1028 3:4003362560 ofp_pkt_processing.c:518] Device IP: 192.168.56.33, Packet Dest IP: 192.168.120.144
D 1032 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0800
D 1032 3:4003362560 ofp_pkt_processing.c:322] Device IP: 192.168.56.33, Packet Dest IP: 224.0.0.251
D 1032 3:4003362560 ofp_pkt_processing.c:203] ip_proto=17 pr_input=0x417610
W 1032 3:4003362560 ofp_udp_usrreq.c:575] badunlocked
D 1036 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0800
D 1036 3:4003362560 ofp_pkt_processing.c:322] Device IP: 192.168.56.33, Packet Dest IP: 224.0.0.251
D 1036 3:4003362560 ofp_pkt_processing.c:203] ip_proto=17 pr_input=0x417610
W 1036 3:4003362560 ofp_udp_usrreq.c:575] badunlocked
D 1040 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0800
D 1040 3:4003362560 ofp_pkt_processing.c:322] Device IP: 192.168.56.33, Packet Dest IP: 224.0.0.251
D 1040 3:4003362560 ofp_pkt_processing.c:203] ip_proto=17 pr_input=0x417610
W 1040 3:4003362560 ofp_udp_usrreq.c:575] badunlocked
D 1044 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 0800
D 1044 3:4003362560 ofp_pkt_processing.c:322] Device IP: 192.168.56.33, Packet Dest IP: 224.0.0.251
D 1044 3:4003362560 ofp_pkt_processing.c:203] ip_proto=17 pr_input=0x417610
W 1044 3:4003362560 ofp_udp_usrreq.c:575] badunlocked
D 1048 3:4003362560 ofp_pkt_processing.c:171] ETH TYPE = 86dd

And my interface messages are:

ens33: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 192.168.120.144  netmask 255.255.255.0  broadcast 192.168.120.255
        inet6 fe80::29e7:56d3:814f:d31  prefixlen 64  scopeid 0x20<link>
        ether 00:0c:29:71:36:06  txqueuelen 1000  (Ethernet)
        RX packets 55583  bytes 79399151 (75.7 MiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 11920  bytes 826615 (807.2 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

fp0: flags=4355<UP,BROADCAST,PROMISC,MULTICAST>  mtu 1500
        inet 192.168.56.33  netmask 255.255.255.0  broadcast 192.168.56.255
        ether ce:3b:20:81:ee:f0  txqueuelen 1000  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

The codes seems to circling in the ofp_pkt_processing.c and keeps trying to add ip address information but failed. In the end, it stuck there or run in circles sometimes.

Besides, the message D 4 1:4160612608 ofp_ifnet.c:225] Interface 'ens33' becomes 'fp0'makes me a little bit confused. Does it mean the system will allocate an arbitrary available port to the web server? If so, the default port 2048 will be useless. Or is that an configuration mistake? Thank you.

bogdanPricope commented 6 years ago

OK. Long story short: send your packets to 192.168.56.33 port 2048 and not 192.168.120.144 port 2048.

This is a misunderstanding on how OFP works:

Note: With other ODP pktio types (e.g. DPDK based pktio type), Linux interface (‘ens33’) is not longer visible with ifconfig. So, it makes sense to have a TAP interface like this, as a source of slow path traffic.

For socket based ODP pktio type (as in your case), ‘ens33’ is still visible with ifconfig but MUST be ignored – should not have IP address, etc. Actually, we need to make sure traffic is not getting to Linux stack through the regular interface by using iptables/ip6tables iptables -A FORWARD -i ens33 -j DROP iptables -A INPUT -i ens33 -j DROP ip6tables -A FORWARD -i ens33 -j DROP ip6tables -A INPUT -i ens33 -j DROP

To revert to initial state: iptables -D FORWARD -i ens33 -j DROP iptables -D INPUT -i ens33 -j DROP ip6tables -D FORWARD -i ens33 -j DROP ip6tables -D INPUT -i ens33 -j DROP