ipv6: possible unsafe locking scenario
Subsystems (3)
hi !
I make the kernel config with CONFIG_PROVE_LOCKING CONFIG_IOSCHED_CFQ CONFIG_PREEMPT_RT_FULL on, and do several test case, it works well, but i notice that the log message has some Call Trace for rwlock, it happens only once, maybe the lock use is not safe in ipv6 and need to improve.
CPU0 CPU1
---- ----
lock(&mc->mca_lock);
lock(&ndev->lock);
lock(&mc->mca_lock); lock(&ndev->lock);
the kernel version is 3.4.24
the test case include LSB.
the problem has report to bugzilla:
https://bugzilla.kernel.org/show_bug.cgi?id=57691&GoAheadAndLogIn=1
following the message:
linux kernel: [ 5913.077146]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077149] ======================================================
Apr 20 11:01:28 euler-linux kernel: [ 5913.077150] [ INFO: possible circular locking dependency detected ]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077154] 3.4.24.05-0.1-default #1 Not tainted
Apr 20 11:01:28 euler-linux kernel: [ 5913.077155] -------------------------------------------------------
Apr 20 11:01:28 euler-linux kernel: [ 5913.077157] ksoftirqd/0/3 is trying to acquire lock:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077158] (&ndev->lock){+.+...}, at: [<ffffffff8147f804>] ipv6_get_lladdr+0x74/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077168]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077169] but task is already holding lock:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077170] (&mc->mca_lock){+.+...}, at: [<ffffffff8149d130>] mld_send_report+0x40/0x150
Apr 20 11:01:28 euler-linux kernel: [ 5913.077177]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077177] which lock already depends on the new lock.
Apr 20 11:01:28 euler-linux kernel: [ 5913.077178]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077179]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077179] the existing dependency chain (in reverse order) is:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077181]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077182] -> #1 (&mc->mca_lock){+.+...}:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077184] [<ffffffff810a8027>] validate_chain+0x637/0x730
Apr 20 11:01:28 euler-linux kernel: [ 5913.077191] [<ffffffff810a8417>] __lock_acquire+0x2f7/0x500
Apr 20 11:01:28 euler-linux kernel: [ 5913.077195] [<ffffffff810a8734>] lock_acquire+0x114/0x150
Apr 20 11:01:28 euler-linux kernel: [ 5913.077198] [<ffffffff814f691a>] rt_spin_lock+0x4a/0x60
Apr 20 11:01:28 euler-linux kernel: [ 5913.077203] [<ffffffff8149e4bb>] igmp6_group_added+0x3b/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077206] [<ffffffff8149e5d8>] ipv6_mc_up+0x38/0x60
Apr 20 11:01:28 euler-linux kernel: [ 5913.077209] [<ffffffff81480a4d>] ipv6_find_idev+0x3d/0x80
Apr 20 11:01:28 euler-linux kernel: [ 5913.077212] [<ffffffff81483175>] addrconf_notify+0x3d5/0x4b0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077215] [<ffffffff814fae3f>] notifier_call_chain+0x3f/0x80
Apr 20 11:01:28 euler-linux kernel: [ 5913.077218] [<ffffffff81073471>] raw_notifier_call_chain+0x11/0x20
Apr 20 11:01:28 euler-linux kernel: [ 5913.077224] [<ffffffff813d8722>] call_netdevice_notifiers+0x32/0x60
Apr 20 11:01:28 euler-linux kernel: [ 5913.077230] [<ffffffff813d92d4>] __dev_notify_flags+0x34/0x80
Apr 20 11:01:28 euler-linux kernel: [ 5913.077233] [<ffffffff813d9360>] dev_change_flags+0x40/0x70
Apr 20 11:01:28 euler-linux kernel: [ 5913.077236] [<ffffffff813ea627>] do_setlink+0x237/0x8a0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077240] [<ffffffff813ebb6c>] rtnl_newlink+0x3ec/0x600
Apr 20 11:01:28 euler-linux kernel: [ 5913.077243] [<ffffffff813eb4d0>] rtnetlink_rcv_msg+0x160/0x310
Apr 20 11:01:28 euler-linux kernel: [ 5913.077246] [<ffffffff814040b9>] netlink_rcv_skb+0x89/0xb0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077251] [<ffffffff813eb357>] rtnetlink_rcv+0x27/0x40
Apr 20 11:01:28 euler-linux kernel: [ 5913.077254] [<ffffffff81403e20>] netlink_unicast+0x140/0x180
Apr 20 11:01:28 euler-linux kernel: [ 5913.077257] [<ffffffff81404a9e>] netlink_sendmsg+0x33e/0x380
Apr 20 11:01:28 euler-linux kernel: [ 5913.077260] [<ffffffff813c4252>] sock_sendmsg+0x112/0x130
Apr 20 11:01:28 euler-linux kernel: [ 5913.077264] [<ffffffff813c537e>] __sys_sendmsg+0x44e/0x460
Apr 20 11:01:28 euler-linux kernel: [ 5913.077267] [<ffffffff813c5544>] sys_sendmsg+0x44/0x70
Apr 20 11:01:28 euler-linux kernel: [ 5913.077269] [<ffffffff814feab9>] system_call_fastpath+0x16/0x1b
Apr 20 11:01:28 euler-linux kernel: [ 5913.077273]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077273] -> #0 (&ndev->lock){+.+...}:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077275] [<ffffffff810a798e>] check_prev_add+0x3de/0x440
Apr 20 11:01:28 euler-linux kernel: [ 5913.077278] [<ffffffff810a8027>] validate_chain+0x637/0x730
Apr 20 11:01:28 euler-linux kernel: [ 5913.077281] [<ffffffff810a8417>] __lock_acquire+0x2f7/0x500
Apr 20 11:01:28 euler-linux kernel: [ 5913.077284] [<ffffffff810a8734>] lock_acquire+0x114/0x150
Apr 20 11:01:28 euler-linux kernel: [ 5913.077287] [<ffffffff814f6c82>] rt_read_lock+0x42/0x60
Apr 20 11:01:28 euler-linux kernel: [ 5913.077290] [<ffffffff8147f804>] ipv6_get_lladdr+0x74/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077293] [<ffffffff8149b036>] mld_newpack+0xb6/0x160
Apr 20 11:01:28 euler-linux kernel: [ 5913.077295] [<ffffffff8149b18b>] add_grhead+0xab/0xc0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077298] [<ffffffff8149d03b>] add_grec+0x3ab/0x460
Apr 20 11:01:28 euler-linux kernel: [ 5913.077301] [<ffffffff8149d14a>] mld_send_report+0x5a/0x150
Apr 20 11:01:28 euler-linux kernel: [ 5913.077304] [<ffffffff8149f99e>] igmp6_timer_handler+0x4e/0xb0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077307] [<ffffffff8105705a>] call_timer_fn+0xca/0x1d0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077312] [<ffffffff81057b9f>] run_timer_softirq+0x1df/0x2e0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077315] [<ffffffff8104e8c7>] handle_pending_softirqs+0xf7/0x1f0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077318] [<ffffffff8104ea3b>] __do_softirq_common+0x7b/0xf0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077320] [<ffffffff8104f07f>] __thread_do_softirq+0x1af/0x210
Apr 20 11:01:28 euler-linux kernel: [ 5913.077323] [<ffffffff8104f1c1>] run_ksoftirqd+0xe1/0x1f0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077325] [<ffffffff8106c7de>] kthread+0xae/0xc0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077327] [<ffffffff814fff74>] kernel_thread_helper+0x4/0x10
Apr 20 11:01:28 euler-linux kernel: [ 5913.077332]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077332] other info that might help us debug this:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077333]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077334] Possible unsafe locking scenario:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077335]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077336] CPU0 CPU1
Apr 20 11:01:28 euler-linux kernel: [ 5913.077337] ---- ----
Apr 20 11:01:28 euler-linux kernel: [ 5913.077338] lock(&mc->mca_lock);
Apr 20 11:01:28 euler-linux kernel: [ 5913.077339] lock(&ndev->lock);
Apr 20 11:01:28 euler-linux kernel: [ 5913.077341] lock(&mc->mca_lock);
Apr 20 11:01:28 euler-linux kernel: [ 5913.077342] lock(&ndev->lock);
Apr 20 11:01:28 euler-linux kernel: [ 5913.077344]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077344] *** DEADLOCK ***
Apr 20 11:01:28 euler-linux kernel: [ 5913.077345]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077346] 4 locks held by ksoftirqd/0/3:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077347] #0: (&per_cpu(local_softirq_lock, __cpu).lock){+.+.+.}, at: [<ffffffff8104ef5e>] __thread_do_softirq+0x8e/0x210
Apr 20 11:01:28 euler-linux kernel: [ 5913.077351] #1: (&mc->mca_timer){+.+...}, at: [<ffffffff81056f90>] call_timer_fn+0x0/0x1d0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077355] #2: (&mc->mca_lock){+.+...}, at: [<ffffffff8149d130>] mld_send_report+0x40/0x150
Apr 20 11:01:28 euler-linux kernel: [ 5913.077359] #3: (rcu_read_lock){.+.+.+}, at: [<ffffffff8147f790>] ipv6_get_lladdr+0x0/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077363]
Apr 20 11:01:28 euler-linux kernel: [ 5913.077363] stack backtrace:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077365] Pid: 3, comm: ksoftirqd/0 Not tainted 3.4.24.05-0.1-default #1
Apr 20 11:01:28 euler-linux kernel: [ 5913.077367] Call Trace:
Apr 20 11:01:28 euler-linux kernel: [ 5913.077371] [<ffffffff810a5abf>] print_circular_bug+0x10f/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077375] [<ffffffff810a798e>] check_prev_add+0x3de/0x440
Apr 20 11:01:28 euler-linux kernel: [ 5913.077378] [<ffffffff810a8027>] validate_chain+0x637/0x730
Apr 20 11:01:28 euler-linux kernel: [ 5913.077381] [<ffffffff810a8417>] __lock_acquire+0x2f7/0x500
Apr 20 11:01:28 euler-linux kernel: [ 5913.077385] [<ffffffff810a8734>] lock_acquire+0x114/0x150
Apr 20 11:01:28 euler-linux kernel: [ 5913.077387] [<ffffffff8147f804>] ? ipv6_get_lladdr+0x74/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077391] [<ffffffff8107a5a1>] ? get_parent_ip+0x11/0x50
Apr 20 11:01:28 euler-linux kernel: [ 5913.077394] [<ffffffff814f6c82>] rt_read_lock+0x42/0x60
Apr 20 11:01:28 euler-linux kernel: [ 5913.077396] [<ffffffff8147f804>] ? ipv6_get_lladdr+0x74/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077399] [<ffffffff8147f804>] ipv6_get_lladdr+0x74/0x120
Apr 20 11:01:28 euler-linux kernel: [ 5913.077401] [<ffffffff8147f790>] ? if6_seq_start+0x100/0x100
Apr 20 11:01:28 euler-linux kernel: [ 5913.077404] [<ffffffff8149b036>] mld_newpack+0xb6/0x160
Apr 20 11:01:28 euler-linux kernel: [ 5913.077407] [<ffffffff810a8417>] ? __lock_acquire+0x2f7/0x500
Apr 20 11:01:28 euler-linux kernel: [ 5913.077410] [<ffffffff8149b18b>] add_grhead+0xab/0xc0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077413] [<ffffffff8149d03b>] add_grec+0x3ab/0x460
Apr 20 11:01:28 euler-linux kernel: [ 5913.077416] [<ffffffff8149f950>] ? ipv6_mc_destroy_dev+0xd0/0xd0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077419] [<ffffffff8149d14a>] mld_send_report+0x5a/0x150
Apr 20 11:01:28 euler-linux kernel: [ 5913.077422] [<ffffffff8149f99e>] igmp6_timer_handler+0x4e/0xb0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077425] [<ffffffff8105705a>] call_timer_fn+0xca/0x1d0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077427] [<ffffffff81056f90>] ? del_timer+0x130/0x130
Apr 20 11:01:28 euler-linux kernel: [ 5913.077431] [<ffffffff8149f950>] ? ipv6_mc_destroy_dev+0xd0/0xd0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077434] [<ffffffff81057b9f>] run_timer_softirq+0x1df/0x2e0
Apr 20 11:01:28 euler-linux kernel: [ 5913.077437] [<ffffffff8104e8c7>] handle_pending_softirqs+0xf7/0x1f0
Apr 20 11:01:29 euler-linux kernel: [ 5913.077439] [<ffffffff8104ea3b>] __do_softirq_common+0x7b/0xf0
Apr 20 11:01:29 euler-linux kernel: [ 5913.077442] [<ffffffff8104f07f>] __thread_do_softirq+0x1af/0x210
Apr 20 11:01:29 euler-linux kernel: [ 5913.077444] [<ffffffff8104f1c1>] run_ksoftirqd+0xe1/0x1f0
Apr 20 11:01:29 euler-linux kernel: [ 5913.077446] [<ffffffff8104f0e0>] ? __thread_do_softirq+0x210/0x210
Apr 20 11:01:29 euler-linux kernel: [ 5913.077449] [<ffffffff8104f0e0>] ? __thread_do_softirq+0x210/0x210
Apr 20 11:01:29 euler-linux kernel: [ 5913.077451] [<ffffffff8106c7de>] kthread+0xae/0xc0
Apr 20 11:01:29 euler-linux kernel: [ 5913.077455] [<ffffffff814fff74>] kernel_thread_helper+0x4/0x10
Apr 20 11:01:29 euler-linux kernel: [ 5913.077459] [<ffffffff8107ad86>] ? finish_task_switch+0x86/0x120
Apr 20 11:01:29 euler-linux kernel: [ 5913.077462] [<ffffffff814f7774>] ? retint_restore_args+0x13/0x13
Apr 20 11:01:29 euler-linux kernel: [ 5913.077465] [<ffffffff8106c730>] ? kthreadd+0x310/0x310
Apr 20 11:01:29 euler-linux kernel: [ 5913.077468] [<ffffffff814fff70>] ? gs_change+0x13/0x13
Apr 20 11:01:29 euler-linux kernel: [ 7880.565457] Adding 12284k swap on /home/swap. Priority:-2 extents:5 across:12588k
Apr 20 11:01:29 euler-linux kernel: [ 7880.832285] Adding 12284k swap on /home/swap. Priority:-2 extents:5 across:12364k
Apr 20 11:01:29 euler-linux kernel: [ 7881.278362] process `sysctl' is using deprecated sysctl (syscall) net.ipv6.neigh.default.base_reachable_time; Use net.ipv6.neigh.default.base_reachable_time_ms instead.Quoted 5 lines · dingtianhong
hi !
I make the kernel config withCONFIG_PROVE_LOCKINGCONFIG_IOSCHED_CFQCONFIG_PREEMPT_RT_FULLon, and do several test case, it works well, but i notice that the log message has some Call Trace for rwlock, it happens only once, maybe the lock use is not safe in ipv6 and need to improve.
Quoted 7 lines
CPU0 CPU1 ---- ---- lock(&mc->mca_lock); lock(&ndev->lock); lock(&mc->mca_lock);
lock(&ndev->lock);
Can you try the following patch?
Thanks.
-------------------->
include/net/addrconf.h +3 -0
@@ -86,6 +86,9 @@ extern int ipv6_dev_get_saddr(struct net *net,const struct in6_addr *daddr, unsigned int srcprefs, struct in6_addr *saddr); +extern int __ipv6_get_lladdr (struct inet6_dev *idev, +struct in6_addr *addr, +unsigned char banned_flags);extern int ipv6_get_lladdr (struct net_device *dev,struct in6_addr *addr,unsigned char banned_flags);
net/ipv6/addrconf.c +18 -10
@@ -1448,6 +1448,23 @@ try_nextdev: }EXPORT_SYMBOL (ipv6_dev_get_saddr); +int __ipv6_get_lladdr (struct inet6_dev *idev,struct in6_addr *addr, +unsigned char banned_flags) +{ +int err = -EADDRNOTAVAIL ; +struct inet6_ifaddr *ifp; + +list_for_each_entry (ifp, &idev->addr_list, if_list) { +if (ifp->scope ==IFA_LINK && + !(ifp->flags & banned_flags)) { + *addr = ifp->addr; + err =0 ; +break ; + } + } +return err; +} +int ipv6_get_lladdr (struct net_device *dev,struct in6_addr *addr,unsigned char banned_flags) {
@@ -1457,17 +1474,8 @@ int ipv6_get_lladdr(struct net_device *dev, struct in6_addr *addr,rcu_read_lock (); idev =__in6_dev_get (dev);if (idev) { -struct inet6_ifaddr *ifp; -read_lock_bh (&idev->lock); -list_for_each_entry (ifp, &idev->addr_list, if_list) { -if (ifp->scope ==IFA_LINK && - !(ifp->flags & banned_flags)) { - *addr = ifp->addr; - err =0 ; -break ; - } - } + err =__ipv6_get_lladdr (idev, addr, banned_flags);read_unlock_bh (&idev->lock); }rcu_read_unlock ();
net/ipv6/mcast.c +10 -8
@@ -1343,8 +1343,9 @@ static void ip6_mc_hdr(struct sock *sk, struct sk_buff *skb, hdr->daddr = *daddr; } -static struct sk_buff *mld_newpack (struct net_device *dev,int size) +static struct sk_buff *mld_newpack (struct inet6_dev *idev,int size) { +struct net_device *dev = idev->dev;struct net *net =dev_net (dev);struct sock *sk = net->ipv6.igmp_sk;struct sk_buff *skb;
@@ -1369,7 +1370,7 @@ static struct sk_buff *mld_newpack(struct net_device *dev, int size)skb_reserve (skb, hlen); -if (ipv6_get_lladdr (dev, &addr_buf,IFA_F_TENTATIVE )) { +if (__ipv6_get_lladdr (idev, &addr_buf,IFA_F_TENTATIVE )) {/* <draft-ietf-magma-mld-source-05.txt>: * use unspecified address as the source address * when a valid link-local address is not available.
@@ -1465,7 +1466,7 @@ static struct sk_buff *add_grhead(struct sk_buff *skb, struct ifmcaddr6 *pmc,struct mld2_grec *pgr;if (!skb) - skb =mld_newpack (dev, dev->mtu); + skb =mld_newpack (pmc->idev, dev->mtu);if (!skb)return NULL ; pgr = (struct mld2_grec *)skb_put (skb,sizeof (struct mld2_grec ));
@@ -1485,7 +1486,8 @@ static struct sk_buff *add_grhead(struct sk_buff *skb, struct ifmcaddr6 *pmc,static struct sk_buff *add_grec (struct sk_buff *skb,struct ifmcaddr6 *pmc,int type,int gdeleted,int sdeleted) { -struct net_device *dev = pmc->idev->dev; +struct inet6_dev *idev = pmc->idev; +struct net_device *dev = idev->dev;struct mld2_report *pmr;struct mld2_grec *pgr =NULL ;struct ip6_sf_list *psf, *psf_next, *psf_prev, **psf_list;
@@ -1514,7 +1516,7 @@ static struct sk_buff *add_grec(struct sk_buff *skb, struct ifmcaddr6 *pmc, AVAILABLE(skb) < grec_size(pmc, type, gdeleted, sdeleted)) {if (skb)mld_sendpack (skb); - skb =mld_newpack (dev, dev->mtu); + skb =mld_newpack (idev, dev->mtu); } } first =1 ;
@@ -1541,7 +1543,7 @@ static struct sk_buff *add_grec(struct sk_buff *skb, struct ifmcaddr6 *pmc, pgr->grec_nsrcs =htons (scount);if (skb)mld_sendpack (skb); - skb =mld_newpack (dev, dev->mtu); + skb =mld_newpack (idev, dev->mtu); first =1 ; scount =0 ; }
@@ -1596,8 +1598,8 @@ static void mld_send_report(struct inet6_dev *idev, struct ifmcaddr6 *pmc)struct sk_buff *skb =NULL ;int type; +read_lock_bh (&idev->lock);if (!pmc) { -read_lock_bh (&idev->lock);for (pmc=idev->mc_list; pmc; pmc=pmc->next) {if (pmc->mca_flags &MAF_NOREPORT )continue ;
@@ -1609,7 +1611,6 @@ static void mld_send_report(struct inet6_dev *idev, struct ifmcaddr6 *pmc) skb =add_grec (skb, pmc, type,0 ,0 );spin_unlock_bh (&pmc->mca_lock); } -read_unlock_bh (&idev->lock); }else {spin_lock_bh (&pmc->mca_lock);if (pmc->mca_sfcount[MCAST_EXCLUDE ])
@@ -1619,6 +1620,7 @@ static void mld_send_report(struct inet6_dev *idev, struct ifmcaddr6 *pmc) skb =add_grec (skb, pmc, type,0 ,0 );spin_unlock_bh (&pmc->mca_lock); } +read_unlock_bh (&idev->lock);if (skb)mld_sendpack (skb); }