mptcpd icon indicating copy to clipboard operation
mptcpd copied to clipboard

Published 20 hours ago • verified publisher icon multipath-tcp

SSPI not creates subflow

Open mix-kao opened this issue 2 years ago • 4 comments

Describe the bug

[Network topology] (iperf3 -s) 198.19.0.96 (A) ---- (B) 198.19.0.32, 198.19.0.33 (iperf3 -c)

Machine B has two interfaces and runs iperf3 as a client to generate traffic to machine A. There is no subflow created by mptcpd.

We also found some unknown messages from mptcpd Unknown MPTCP_EVENT_SUB_* attribute: 2 Unknown MPTCP_EVENT_SUB_* attribute: 3 Unknown MPTCP_EVENT_SUB_* attribute: 4 Unknown MPTCP_EVENT_SUB_* attribute: 15

To Reproduce Steps to reproduce the behavior:

  1. echo 1 > /proc/sys/net/mptcp/mptcp_debug; echo netlink > /proc/sys/net/mptcp/mptcp_path_manager
  2. Run mptcpd in machine A and B ./mptcpd --load-plugins=sspi -d --notify-flags=existing,skip_link_local,skip_loopback
  3. Run iperf3 -c 198.19.0.96 to generate TCP traffic from B to A
  4. Check the dmesg and can not get any subflow from debug message.

Expected behavior Expect mptcpd can create a subflow from B to A, but the result is the subflow is not created.

Screenshots [Machine B] We add some debug message in mptcpd $ /root/abc/libexec/mptcpd --load-plugins=sspi -d --notify-flags=existing,skip_link_local,skip_loopback configuration.c:mptcpd_config_create() path manager plugin directory: /root/abc/lib/mptcpd configuration.c:mptcpd_config_create() default path manager plugin: sspi configuration.c:mptcpd_config_create() notify flags: existing,skip_link_local,skip_loopback configuration.c:mptcpd_config_create() plugins to load: sspi netlink_pm_mptcp_org.c:mptcpd_get_netlink_pm() mptcpd was built with support for the multipath-tcp.org kernel. path_manager.c:family_appeared() "mptcp" generic netlink family appeared MPTCP single-subflow-per-interface path manager initialized. sspi_new_local_address, The new local IP address is: 125.227.11.57, id=1 sspi_new_local_address, The new local IP address is: 122.146.95.178, id=2 sspi_new_local_address, The new local IP address is: 10.17.113.242, id=3 sspi_new_local_address, The new local IP address is: 192.168.131.254, id=4 sspi_new_local_address, The new local IP address is: 198.18.254.1, id=5 sspi_new_local_address, The new local IP address is: 198.19.0.32, id=6 sspi_new_local_address, The new local IP address is: 198.19.0.33, id=7

sspi_new_connection, The local IP address is: 198.19.0.32 sspi_new_connection, The remote IP address is: 198.19.0.96

mptcp_org_add_addr, ret=2

sspi_send_addr, The IP sockaddr is: 198.19.0.33, address_id=7, info->index=20, info->token=4e31945, result=119

sspi_connection_established, The local IP address is: 198.19.0.32, remote IP address is: 198.19.0.96, token is 4e31945 sspi_connection_established is unimplemented.

sspi_new_connection, The local IP address is: 198.19.0.32 sspi_new_connection, The remote IP address is: 198.19.0.96

mptcp_org_add_addr, ret=3

sspi_send_addr, The IP sockaddr is: 198.19.0.33, address_id=7, info->index=20, info->token=53164307, result=-15857316

sspi_connection_established, The local IP address is: 198.19.0.32, remote IP address is: 198.19.0.96, token is 53164307 sspi_connection_established is unimplemented.

Unknown MPTCP_EVENT_SUB_ attribute: 2 Unknown MPTCP_EVENT_SUB_ attribute: 3 Unknown MPTCP_EVENT_SUB_* attribute: 4 Unknown MPTCP_EVENT_SUB_* attribute: 15**

sspi_subflow_closed, The local IP address is: 198.19.0.32 sspi_subflow_closed, The remote IP address is: 198.19.0.96 Closed subflow was not tracked on network interface 20. sspi_connection_closed sspi_remove_token Untracked connection closed. sspi_connection_closed sspi_remove_token

[Machine B dmesg] mptcp_alloc_mpcb: created mpcb with token 0x4e31945 mptcp_add_sock: token 0x4e31945 pi 1, src_addr:198.19.0.32:55336 dst_addr:198.19.0.96:9877 mptcp_netlink: mptcp_nl_pm_new_session:279 mptcp_netlink: mptcp_nl_genl_announce:627 mptcp_netlink: mptcp_nl_pm_get_local_id:498 mptcp_netlink: mptcp_nl_genl_announce:672, addr_id=7 [i=0], ifidx=0, ip=198.19.0.33, token=4e31945 mptcp_netlink: mptcp_nl_pm_addr_signal:538: saddr=198.19.0.32:55336, daddr=198.19.0.96:9877, mptcp_netlink: mptcp_nl_pm_addr_signal:550, loc4_id=7, addr=198.19.0.33 mptcp_netlink: mptcp_nl_pm_fully_established:372 mptcp_netlink: mptcp_nl_sk_setup_locaddr:324

mptcp_alloc_mpcb: created mpcb with token 0x53164307 mptcp_add_sock: token 0x53164307 pi 1, src_addr:198.19.0.32:55338 dst_addr:198.19.0.96:9877 mptcp_netlink: mptcp_nl_pm_new_session:279 mptcp_netlink: mptcp_nl_genl_announce:627 mptcp_netlink: mptcp_nl_pm_get_local_id:498 mptcp_netlink: mptcp_nl_genl_announce:672, addr_id=7 [i=0], ifidx=0, ip=198.19.0.33, token=53164307 mptcp_netlink: mptcp_nl_pm_addr_signal:538: saddr=198.19.0.32:55338, daddr=198.19.0.96:9877, mptcp_netlink: mptcp_nl_pm_addr_signal:550, loc4_id=7, addr=198.19.0.33 mptcp_netlink: mptcp_nl_pm_fully_established:372 mptcp_netlink: mptcp_nl_sk_setup_locaddr:324

mptcp_close: Close of meta_sk with tok 0x53164307 mptcp_netlink: mptcp_nl_pm_delete_subflow:410 mptcp_del_sock: Removing subsock tok 0x53164307 pi:1 state 7 is_meta? 0 mptcp_netlink: mptcp_nl_pm_close_session:387 mptcp_sock_destruct destroying meta-sk token 0x53164307 mptcp_close: Close of meta_sk with tok 0x4e31945 mptcp_netlink: mptcp_nl_pm_close_session:387 mptcp_netlink: mptcp_nl_pm_delete_subflow:410 mptcp_del_sock: Removing subsock tok 0x4e31945 pi:1 state 7 is_meta? 0 mptcp_sock_destruct destroying meta-sk token 0x4e31945

[Machine A mptcpd debu log] $ /root/abc/libexec/mptcpd --load-plugins=sspi -d --notify-flags=existing,skip_l ink_local,skip_loopback configuration.c:mptcpd_config_create() path manager plugin directory: /root/abc/lib/mptcpd configuration.c:mptcpd_config_create() default path manager plugin: sspi configuration.c:mptcpd_config_create() notify flags: existing,skip_link_local,skip_loopback configuration.c:mptcpd_config_create() plugins to load: sspi netlink_pm_mptcp_org.c:mptcpd_get_netlink_pm() mptcpd was built with support for the multipath-tcp.org kernel. path_manager.c:family_appeared() "mptcp" generic netlink family appeared MPTCP single-subflow-per-interface path manager initialized. sspi_new_local_address, The new local IP address is: 172.17.28.95, id=1 sspi_new_local_address, The new local IP address is: 192.168.239.254, id=2 sspi_new_local_address, The new local IP address is: 198.18.254.1, id=3 sspi_new_local_address, The new local IP address is: 198.19.0.96, id=4

sspi_new_connection, The local IP address is: 198.19.0.96 sspi_new_connection, The remote IP address is: 198.19.0.32

Unknown MPTCP_EVENT_ANNOUNCED attribute: 2 sspi_new_address, Get the new IP address from remote is: 198.19.0.33, aid=7, token=e2b89c19 sspi_connection_established, The local IP address is: 198.19.0.96, remote IP address is: 198.19.0.32, token is e2b89c19 sspi_connection_established is unimplemented.

sspi_new_connection, The local IP address is: 198.19.0.96 sspi_new_connection, The remote IP address is: 198.19.0.32

Unknown MPTCP_EVENT_ANNOUNCED attribute: 2 sspi_new_address, Get the new IP address from remote is: 198.19.0.33, aid=7, token=f5a0ea3e sspi_connection_established, The local IP address is: 198.19.0.96, remote IP address is: 198.19.0.32, token is f5a0ea3e

sspi_connection_established is unimplemented. sspi_connection_closed sspi_remove_token sspi_connection_closed Untracked connection closed.

[Machine A dmesg] mptcp_alloc_mpcb: created mpcb with token 0xe2b89c19 mptcp_add_sock: token 0xe2b89c19 pi 1, src_addr:198.19.0.96:9877 dst_addr:198.19.0.32:55336 mptcp_netlink: mptcp_nl_pm_new_session:279 mptcp_netlink: mptcp_nl_pm_add_raddr:424, remote new addr: 198.19.0.33, id=7 mptcp_netlink: mptcp_nl_pm_fully_established:372 mptcp_netlink: mptcp_nl_sk_setup_locaddr:324 mptcp_alloc_mpcb: created mpcb with token 0xf5a0ea3e mptcp_add_sock: token 0xf5a0ea3e pi 1, src_addr:198.19.0.96:9877 dst_addr:198.19.0.32:55338 mptcp_netlink: mptcp_nl_pm_new_session:279 mptcp_netlink: mptcp_nl_pm_add_raddr:424, remote new addr: 198.19.0.33, id=7 mptcp_netlink: mptcp_nl_pm_fully_established:372 mptcp_netlink: mptcp_nl_sk_setup_locaddr:324 mptcp_close: Close of meta_sk with tok 0xf5a0ea3e mptcp_netlink: mptcp_nl_pm_close_session:387 mptcp_netlink: mptcp_nl_pm_delete_subflow:410 mptcp_del_sock: Removing subsock tok 0xf5a0ea3e pi:1 state 7 is_meta? 0 mptcp_sock_destruct destroying meta-sk token 0xf5a0ea3e mptcp_close: Close of meta_sk with tok 0xe2b89c19 mptcp_netlink: mptcp_nl_pm_close_session:387 mptcp_netlink: mptcp_nl_pm_delete_subflow:410 mptcp_del_sock: Removing subsock tok 0xe2b89c19 pi:1 state 7 is_meta? 0 mptcp_sock_destruct destroying meta-sk token 0xe2b89c19

Desktop (please complete the following information):

  • Linux Kernel: 5.4
  • mptcpd version 0.9
    • Applied -> sspi: Generate and remove MPTCP address ID as needed. #234

Additional context Switch path manager to fullmesh echo fullmesh > /proc/sys/net/mptcp/mptcp_path_manager Repeat the procedure mentioned above. We can get the subflow created by the kernel path manager.

$ dmesg (machine B) mptcp_alloc_mpcb: created mpcb with token 0x2adb01f5 mptcp_add_sock: token 0x2adb01f5 pi 1, src_addr:198.19.0.32:55268 dst_addr:198.19.0.96:9877 mptcp_add_sock: token 0x2adb01f5 pi 2, src_addr:0.0.0.0:0 dst_addr:0.0.0.0:0 __mptcp_init4_subsockets: tokenbb 0x2adb01f5 pi 2 src_addr:198.19.0.33:0 dst_addr:198.19.0.96:9877 ifidx: 21 loc4_id:3 mptcp_alloc_mpcb: created mpcb with token 0x1bb8123b mptcp_add_sock: token 0x1bb8123b pi 1, src_addr:198.19.0.32:55270 dst_addr:198.19.0.96:9877 mptcp_add_sock: token 0x1bb8123b pi 2, src_addr:0.0.0.0:0 dst_addr:0.0.0.0:0 __mptcp_init4_subsockets: tokenbb 0x1bb8123b pi 2 src_addr:198.19.0.33:0 dst_addr:198.19.0.96:9877 ifidx: 21 loc4_id:3 mptcp_close: Close of meta_sk with tok 0x1bb8123b mptcp_del_sock: Removing subsock tok 0x1bb8123b pi:2 state 7 is_meta? 0 mptcp_del_sock: Removing subsock tok 0x1bb8123b pi:1 state 7 is_meta? 0 mptcp_sock_destruct destroying meta-sk token 0x1bb8123b mptcp_del_sock: Removing subsock tok 0x2adb01f5 pi:2 state 7 is_meta? 0 mptcp_close: Close of meta_sk with tok 0x2adb01f5 mptcp_del_sock: Removing subsock tok 0x2adb01f5 pi:1 state 7 is_meta? 0 mptcp_sock_destruct destroying meta-sk token 0x2adb01f5

mix-kao avatar Jun 14 '22 10:06 mix-kao

We call the API -> mptcpd_pm_add_subflow() in sspi_connection_established() with hardcode parameters, it seems the subflow can create by the kernel.

[ 2359.305075] mptcp_alloc_mpcb: created mpcb with token 0x96c5c108 [ 2359.305680] mptcp_add_sock: token 0x96c5c108 pi 1, src_addr:198.19.0.32:44084 dst_addr:198.19.0.96:9877 [ 2359.327849] mptcp_add_sock: token 0x96c5c108 pi 2, src_addr:0.0.0.0:0 dst_addr:0.0.0.0:0 [ 2359.328666] __mptcp_init4_subsockets: tokenbb 0x96c5c108 pi 2 src_addr:198.19.0.33:0 dst_addr:198.19.0.96:9877 ifidx: 21 loc4_id:7 [ 2450.596318] mptcp_close: Close of meta_sk with tok 0x96c5c108 [ 2450.607116] mptcp_del_sock: Removing subsock tok 0x96c5c108 pi:2 state 7 is_meta? 0 [ 2450.607127] mptcp_del_sock: Removing subsock tok 0x96c5c108 pi:1 state 7 is_meta? 0 [ 2450.613687] mptcp_sock_destruct destroying meta-sk token 0x96c5c108

We have a question, where is the right place to call the mptcpd_pm_add_subflow() in mptcpd?

mix-kao avatar Jun 17 '22 10:06 mix-kao

We call the API -> mptcpd_pm_add_subflow() in sspi_connection_established() with hardcode parameters, it seems the subflow can create by the kernel. ... We have a question, where is the right place to call the mptcpd_pm_add_subflow() in mptcpd?

Doing so after the MPTCP connection is established should be fine. I'll try to reproduce the problem on my end. Thanks for the bug report!

ossama-othman avatar Jun 27 '22 17:06 ossama-othman

We call the API -> mptcpd_pm_add_subflow() in sspi_connection_established() with hardcode parameters, it seems the subflow can create by the kernel. ... We have a question, where is the right place to call the mptcpd_pm_add_subflow() in mptcpd?

Doing so after the MPTCP connection is established should be fine. I'll try to reproduce the problem on my end. Thanks for the bug report!

@ossama-othman Thanks for the reply. Still have some questions to ask.

  1. When the function of sspi_new_subflow be called? In my understanding, the client requests a subflow to the server, and the server replies ok to establish the subflow, at this moment, the client's mptcpd received MPTCP_EVENT_SUB_ESTABLISHED event from the kernel and then calls the sspi_new_subflow function. Correct me if I'm wrong :)

  2. SSPI (Single Subflow Per Interface) For example: A, B, and C, all have only one interface. Server (C) <-------> Client (A) <-------> Server (B)

Case 1: A initiates MPTCP connection to B (token: ABC) Case 2: A initiates MPTCP connection to C (token: DEF)

Can "Case 1" and "Case 2" both work at the same time or not? Does SSPI mean Client A only can create a subflow? (A to B, then A to C will fail?)

Thanks :)

mix-kao avatar Jun 29 '22 08:06 mix-kao

Hello @ossama-othman

Have you been able to reproduce the bug from your end? Can you provide any pointer regarding its progress.

abhinaba-fbr avatar Oct 14 '22 04:10 abhinaba-fbr