On Wed, May 20, 2020 at 05:42:35PM +0300, Vitaliy Makkoveev wrote:
> I got splassert with pppx(4) and net/ifq.c rev 1.38 raised by
> NET_ASSERT_LOCKED() in netinet/ip_output.c:113 and underlaying routines.
>
> net/ifq.c rev 1.38 is not in snapshot yet so you need to checkout and
> build kernel to reproduce.
>
> ---- dmesg begin ----
>
> splassert: ip_output: want 2 have 0
> Starting stack trace...
> ip_output(fffffd801f8c8800,0,0,0,0,0) at ip_output+0x8f
> pipex_l2tp_output(fffffd801f8c8800,ffff80000e787808) at
> pipex_l2tp_output+0x21d
> pipex_ppp_output(fffffd801f8c8800,ffff80000e787808,21) at
> pipex_ppp_output+0xda
> pppx_if_start(ffff80000e787268) at pppx_if_start+0x83
> if_qstart_compat(ffff80000e7874e0) at if_qstart_compat+0x2e
> ifq_serialize(ffff80000e7874e0,ffff80000e7875b0) at ifq_serialize+0x103
> taskq_thread(ffffffff81f3df30) at taskq_thread+0x4d
> end trace frame: 0x0, count: 250
> End of stack trace.
> splassert: ipsp_spd_lookup: want 2 have 0
> Starting stack trace...
> ipsp_spd_lookup(fffffd801f8c8800,2,14,ffff80000e726c9c,2,0) at
> ipsp_spd_lookup+0x80
> ip_output_ipsec_lookup(fffffd801f8c8800,14,ffff80000e726c9c,0,1) at
> ip_output_ipsec_lookup+0x4d
> ip_output(fffffd801f8c8800,0,0,0,0,0) at ip_output+0x4fa
> pipex_l2tp_output(fffffd801f8c8800,ffff80000e787808) at
> pipex_l2tp_output+0x21d
> pipex_ppp_output(fffffd801f8c8800,ffff80000e787808,21) at
> pipex_ppp_output+0xda
> pppx_if_start(ffff80000e787268) at pppx_if_start+0x83
> if_qstart_compat(ffff80000e7874e0) at if_qstart_compat+0x2e
> ifq_serialize(ffff80000e7874e0,ffff80000e7875b0) at ifq_serialize+0x103
> taskq_thread(ffffffff81f3df30) at taskq_thread+0x4d
> end trace frame: 0x0, count: 248
> End of stack trace.
> splassert: spd_table_get: want 2 have 0
>
> ---- dmesg end ----
>
> 1. `pxi_if' owned by struct pppx_if has IFXF_MPSAFE flag unset
> 1.1 pppx(4) sets IFQ_SET_MAXLEN(&ifp->if_snd, 1) at net/if_pppx.c:866
> 2. pppx_if_output() is called under NET_LOCK()
> 3. pppx_if_output() calls if_enqueue() at net/if_pppx.c:1123
> 4. pppx(4) doesn't set `ifp->if_enqueue' so if_enqueue() calls
> if_enqueue_ifq() at net/if.c:709 (which is set in net/if.c:639)
> 5. if_enqueue_ifq() calls ifq_start() at net/if.c:734
> 6. ifq_start() we a still under NET_LOCK() here
>
> 6.a. in net/ifq.c rev 1.37 ifq_start() checks "ifq_len(ifq) >=
> min(ifp->if_txmit, ifq->ifq_maxlen)" and this was always true because
> (1.1) so we always call ifq_run_start() which calls ifq_serialize().
>
> ifq_serialize() will call if_qstart_compat() which calls
> pppx_if_start() which calls pipex_ppp_output() etc while we still
> holding NET_LOCK() so the assertions I reported above are not raised.
>
> 6.b. net/ifq.c rev 1.38 introduce checks of IFXF_MPSAFE flag. so we are
> always going to net/ifq.c:132 where we adding out task to `systq'
> referenced by `ifq_softnet' (ifq_softnet set to `systq' at
> net/ifq.c:199).
>
> taskq_thread() doesn't grab NET_LOCK() so after net/ifq.c rev 1.38
> ifq_serialize() and underlaying pppx_if_start() call without NET_LOCK()
> and corresponding asserts raised.
>
> The problem I pointed is not in net/ifq.c rev 1.38 but in pppx(4).
> `if_start' routines should grab NET_LOCK() by themself if it is required
> but pppx_if_start() and pppac_start() did't do that. pppac_start() has
> no underlaying NET_ASSERT_LOCKED() so the pppx(4) is the only case were
> the problem is shown.
>
> Since NET_LOCK() is required by pipex(4), diff below adds it to
> pppx_if_start() and pppac_start().
>
> After net/ifq.c rev 1.38 pppx_if_start() will newer be called from
> pppx_if_output() but from `systq' only so I don't add lock/unlock
> dances around if_enqueue() at net/if_pppx.c:1123.
>
> Diff tested for both pppx(4) and pppac(4) cases.
thanks for the detailed analysis. i wondered how the ifq change
triggered this exactly, and your mail makes it clear.
however, pppx/pppac/pipex are not the first or only drivers in the tree
that encapsulate a packet in IP from their if_start routine and send it
out with the network stack. the way this has been solved in every other
driver has been to call ip{,6}_send to transmit the packet instead
of ip{,6}_output.
can you try the following diff?
Index: pipex.c
===================================================================
RCS file: /cvs/src/sys/net/pipex.c,v
retrieving revision 1.113
diff -u -p -r1.113 pipex.c
--- pipex.c 7 Apr 2020 07:11:22 -0000 1.113
+++ pipex.c 21 May 2020 21:49:50 -0000
@@ -1453,10 +1453,7 @@ pipex_pptp_output(struct mbuf *m0, struc
gre->flags = htons(gre->flags);
m0->m_pkthdr.ph_ifidx = session->pipex_iface->ifnet_this->if_index;
- if (ip_output(m0, NULL, NULL, 0, NULL, NULL, 0) != 0) {
- PIPEX_DBG((session, LOG_DEBUG, "ip_output failed."));
- goto drop;
- }
+ ip_send(m0);
if (len > 0) { /* network layer only */
/* countup statistics */
session->stat.opackets++;
@@ -1901,11 +1898,7 @@ pipex_l2tp_output(struct mbuf *m0, struc
ip->ip_tos = 0;
ip->ip_off = 0;
- if (ip_output(m0, NULL, NULL, 0, NULL, NULL,
- session->proto.l2tp.ipsecflowinfo) != 0) {
- PIPEX_DBG((session, LOG_DEBUG, "ip_output failed."));
- goto drop;
- }
+ ip_send(m0);
break;
#ifdef INET6
case AF_INET6:
@@ -1920,10 +1913,7 @@ pipex_l2tp_output(struct mbuf *m0, struc
&session->peer.sin6, NULL);
/* ip6->ip6_plen will be filled in ip6_output. */
- if (ip6_output(m0, NULL, NULL, 0, NULL, NULL) != 0) {
- PIPEX_DBG((session, LOG_DEBUG, "ip6_output failed."));
- goto drop;
- }
+ ip6_send(m0);
break;
#endif
}
