unix stream crashes

Hi,

my box 100% crashes when booting. It's both in unix socket recv and send paths. I've reverted 0856a30409 (Scm: Remove unnecessary pid & credential references in Unix socket's send and receive path) and it seems to help.

The oops:
http://www.fi.muni.cz/~xslaby/sklad/panics/af_unix_crash.png

regards,

js

I was seeing a 100% repeatable crash with the X server starting as well, but wasn't able to get a traceback because my X server was doing the modeset before it crashed (so all I got was a black screen) and netconsole is busticated for me. I can confirm that reverting that one commit allows my box to boot and get X up and running as well.

Yes, Jiri's log does indicate that something went wrong when releasing the skb, most likely due to changes in the pid and credentials ref count. Unfortunately, I cannot duplicate the problem on my system. Any info on your system to help me debug will be appreciated. I'll try to take another look at the patch tomorrow.

Tim

Dell Latitude E6500, Core2 T8700 processor, x86_64 kernel, a slightly mangled Fedora Rawhide userspace. I'd not be surprised if there's an idiocyncratic setting in my .config that makes the bug crawl out of the woodwork on my box, so I'm attaching the .config in case it provides some enlightenment.

If you want me to try a debugging or test patch, let me know...

Valdis,

I've tried your config on a few different machines but I'm still not able to reproduce the problem. Can you help me narrow things down? Please revert my original patch. I've separated my original changes into two parts. Try apply only the recv_scm.patch attached and try to boot. Then apply only the send_scm.patch without the rcv_scm.patch and repeat. Let me know which patch causes the boot problem.

I'll like to isolate the problem to either the send path or receive path. My suspicion is the error handling portion of the send path is not quite right but I haven't yet found any issues after reviewing the patch.

Thanks.

Tim

index 745460f..68e1e48 100644
@@ -53,6 +53,14 @@ static __inline__ void scm_set_cred(struct scm_cookie *scm,
 	cred_to_ucred(pid, cred, &scm->creds);
 }
 
+static __inline__ void scm_set_cred_noref(struct scm_cookie *scm,
+				    struct pid *pid, const struct cred *cred)
+{
+	scm->pid  = pid;
+	scm->cred = cred;
+	cred_to_ucred(pid, cred, &scm->creds);
+}
+
 static __inline__ void scm_destroy_cred(struct scm_cookie *scm)
 {
 	put_pid(scm->pid);

@@ -108,15 +125,14 @@ static __inline__ void scm_recv(struct socket *sock, struct msghdr *msg,
 	if (!msg->msg_control) {
 		if (test_bit(SOCK_PASSCRED, &sock->flags) || scm->fp)
 			msg->msg_flags |= MSG_CTRUNC;
-		scm_destroy(scm);
+		if (scm && scm->fp)
+			__scm_destroy(scm);
 		return;
 	}
 
 	if (test_bit(SOCK_PASSCRED, &sock->flags))
 		put_cmsg(msg, SOL_SOCKET, SCM_CREDENTIALS, sizeof(scm->creds), &scm->creds);
 
-	scm_destroy_cred(scm);
-
 	scm_passec(sock, msg, scm);
 
 	if (!scm->fp)

index ec68e1c..e6d9d10 100644
@@ -1777,7 +1789,7 @@ static int unix_dgram_recvmsg(struct kiocb *iocb, struct socket *sock,
 		siocb->scm = &tmp_scm;
 		memset(&tmp_scm, 0, sizeof(tmp_scm));
 	}
-	scm_set_cred(siocb->scm, UNIXCB(skb).pid, UNIXCB(skb).cred);
+	scm_set_cred_noref(siocb->scm, UNIXCB(skb).pid, UNIXCB(skb).cred);
 	unix_set_secdata(siocb->scm, skb);
 
 	if (!(flags & MSG_PEEK)) {

@@ -1939,7 +1951,8 @@ static int unix_stream_recvmsg(struct kiocb *iocb, struct socket *sock,
 			}
 		} else {
 			/* Copy credentials */
-			scm_set_cred(siocb->scm, UNIXCB(skb).pid, UNIXCB(skb).cred);
+			scm_set_cred_noref(siocb->scm, UNIXCB(skb).pid,
+					   UNIXCB(skb).cred);
 			check_creds = 1;
 		}
 

index 745460f..68e1e48 100644
@@ -70,6 +78,15 @@ static __inline__ void scm_destroy(struct scm_cookie *scm)
 		__scm_destroy(scm);
 }
 
+static __inline__ void scm_release(struct scm_cookie *scm)
+{
+	/* keep ref on pid and cred */
+	scm->pid = NULL;
+	scm->cred = NULL;
+	if (scm->fp)
+		__scm_destroy(scm);
+}
+
 static __inline__ int scm_send(struct socket *sock, struct msghdr *msg,
 			       struct scm_cookie *scm)
 {

index ec68e1c..e6d9d10 100644
@@ -1378,11 +1378,17 @@ static int unix_attach_fds(struct scm_cookie *scm, struct sk_buff *skb)
 	return max_level;
 }
 
-static int unix_scm_to_skb(struct scm_cookie *scm, struct sk_buff *skb, bool send_fds)
+static int unix_scm_to_skb(struct scm_cookie *scm, struct sk_buff *skb,
+			   bool send_fds, bool ref)
 {
 	int err = 0;
-	UNIXCB(skb).pid  = get_pid(scm->pid);
-	UNIXCB(skb).cred = get_cred(scm->cred);
+	if (ref) {
+		UNIXCB(skb).pid  = get_pid(scm->pid);
+		UNIXCB(skb).cred = get_cred(scm->cred);
+	} else {
+		UNIXCB(skb).pid  = scm->pid;
+		UNIXCB(skb).cred = scm->cred;
+	}
 	UNIXCB(skb).fp = NULL;
 	if (scm->fp && send_fds)
 		err = unix_attach_fds(scm, skb);

@@ -1407,7 +1413,7 @@ static int unix_dgram_sendmsg(struct kiocb *kiocb, struct socket *sock,
 	int namelen = 0; /* fake GCC */
 	int err;
 	unsigned hash;
-	struct sk_buff *skb;
+	struct sk_buff *skb = NULL;
 	long timeo;
 	struct scm_cookie tmp_scm;
 	int max_level;

@@ -1448,7 +1454,7 @@ static int unix_dgram_sendmsg(struct kiocb *kiocb, struct socket *sock,
 	if (skb == NULL)
 		goto out;
 
-	err = unix_scm_to_skb(siocb->scm, skb, true);
+	err = unix_scm_to_skb(siocb->scm, skb, true, false);
 	if (err < 0)
 		goto out_free;
 	max_level = err + 1;

@@ -1544,7 +1550,7 @@ restart:
 	unix_state_unlock(other);
 	other->sk_data_ready(other, len);
 	sock_put(other);
-	scm_destroy(siocb->scm);
+	scm_release(siocb->scm);
 	return len;
 
 out_unlock:

@@ -1554,7 +1560,8 @@ out_free:
 out:
 	if (other)
 		sock_put(other);
-	scm_destroy(siocb->scm);
+	if (skb == NULL)
+		scm_destroy(siocb->scm);
 	return err;
 }
 

@@ -1566,7 +1573,7 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 	struct sock *sk = sock->sk;
 	struct sock *other = NULL;
 	int err, size;
-	struct sk_buff *skb;
+	struct sk_buff *skb = NULL;
 	int sent = 0;
 	struct scm_cookie tmp_scm;
 	bool fds_sent = false;

@@ -1631,11 +1638,11 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 		size = min_t(int, size, skb_tailroom(skb));
 
 
-		/* Only send the fds in the first buffer */
-		err = unix_scm_to_skb(siocb->scm, skb, !fds_sent);
+		/* Only send the fds and no ref to pid in the first buffer */
+		err = unix_scm_to_skb(siocb->scm, skb, !fds_sent, fds_sent);
 		if (err < 0) {
 			kfree_skb(skb);
-			goto out_err;
+			goto out;
 		}
 		max_level = err + 1;
 		fds_sent = true;

@@ -1643,7 +1650,7 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 		err = memcpy_fromiovec(skb_put(skb, size), msg->msg_iov, size);
 		if (err) {
 			kfree_skb(skb);
-			goto out_err;
+			goto out;
 		}
 
 		unix_state_lock(other);

@@ -1660,7 +1667,10 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 		sent += size;
 	}
 
-	scm_destroy(siocb->scm);
+	if (skb)
+		scm_release(siocb->scm);
+	else
+		scm_destroy(siocb->scm);
 	siocb->scm = NULL;
 
 	return sent;

@@ -1673,7 +1683,9 @@ pipe_err:
 		send_sig(SIGPIPE, current, 0);
 	err = -EPIPE;
 out_err:
-	scm_destroy(siocb->scm);
+	if (skb == NULL)
+		scm_destroy(siocb->scm);
+out:
 	siocb->scm = NULL;
 	return sent ? : err;
 }

Hi,

base for my testing was linux-next (next-20110826) which contains first time the culprit commit.
I have tested on an i386 Debian/sid system, my kernel-config is attached.

BAD #1: next-20110826

GOOD #1: next-20110826 + Revert-patch

GOOD #2: next-20110826 + Revert-patch + scm_recv.patch

BAD #2: next-20110826 + Revert-patch + scm_send.patch

With BAD #2 I have seen a NULL derefence (*pde = 00000000) arosing from kmem_cache_alloc_trace().
( Sorry, no digicam here for a screenshot. )

Hope this helps you.

Feel free to send me further patches and/or add a
Reported-by/Tested-by/Bisected-by if you like.

- Sedat -

From 827255d53008e66628acc83e6c7692cbe2dc1ba0 Mon Sep 17 00:00:00 2001
From: Sedat Dilek <[email protected]>
Date: Fri, 2 Sep 2011 23:55:46 +0200
Subject: [PATCH] Revert "Scm: Remove unnecessary pid & credential references
in Unix socket's send and receive path"

This reverts commit 0856a304091b33a8e8f9f9c98e776f425af2b625.

---
 include/net/scm.h  |   22 +++-------------------
 net/unix/af_unix.c |   45 ++++++++++++++++-----------------------------
 2 files changed, 19 insertions(+), 48 deletions(-)

index 68e1e48..745460f 100644
@@ -53,14 +53,6 @@ static __inline__ void scm_set_cred(struct scm_cookie *scm,
 	cred_to_ucred(pid, cred, &scm->creds);
 }
 
-static __inline__ void scm_set_cred_noref(struct scm_cookie *scm,
-				    struct pid *pid, const struct cred *cred)
-{
-	scm->pid  = pid;
-	scm->cred = cred;
-	cred_to_ucred(pid, cred, &scm->creds);
-}
-
 static __inline__ void scm_destroy_cred(struct scm_cookie *scm)
 {
 	put_pid(scm->pid);

@@ -78,15 +70,6 @@ static __inline__ void scm_destroy(struct scm_cookie *scm)
 		__scm_destroy(scm);
 }
 
-static __inline__ void scm_release(struct scm_cookie *scm)
-{
-	/* keep ref on pid and cred */
-	scm->pid = NULL;
-	scm->cred = NULL;
-	if (scm->fp)
-		__scm_destroy(scm);
-}
-
 static __inline__ int scm_send(struct socket *sock, struct msghdr *msg,
 			       struct scm_cookie *scm)
 {

@@ -125,14 +108,15 @@ static __inline__ void scm_recv(struct socket *sock, struct msghdr *msg,
 	if (!msg->msg_control) {
 		if (test_bit(SOCK_PASSCRED, &sock->flags) || scm->fp)
 			msg->msg_flags |= MSG_CTRUNC;
-		if (scm && scm->fp)
-			__scm_destroy(scm);
+		scm_destroy(scm);
 		return;
 	}
 
 	if (test_bit(SOCK_PASSCRED, &sock->flags))
 		put_cmsg(msg, SOL_SOCKET, SCM_CREDENTIALS, sizeof(scm->creds), &scm->creds);
 
+	scm_destroy_cred(scm);
+
 	scm_passec(sock, msg, scm);
 
 	if (!scm->fp)

1.7.6

Took a while, because it took a few tries to get netconsole working, and then I was seeing odd results, but here we go:

next-20110831 - crashes 100% consistent. next-20110831 + revert 0856a30409 - OK. revert + scm_recv.patch - OK.
revert + scm_send.patch - crashes 100% consistent.

Now the odd part - although I was seeing crashes 100% of the time, I saw a number of different tracebacks (but I never actually saw the same traceback that Jiri had). Also, the system died at different points - most of the time it would live long enough for GDM to prompt for a userid/password and then die, but sometimes it didn't get as far as the GDM screen. Hopefully the variety of crashes will tell you something useful.

I'll be able to test patches for go/nogo over the weekend, but probably won't have a second machine to catch netconsole until I'm back in the office Monday.

Example 1:

[  142.316258] Kernel panic - not syncing: CRED: put_cred_rcu() sees ffff88010d1ff300 with usage -41
[  142.316260] 
[  142.316275] Pid: 2264, comm: gdm-simple-slav Tainted: G        W   3.1.0-rc4-next-20110831-dirty #17
[  142.316279] Call Trace:
[  142.316283]  <IRQ>  [<ffffffff81577a6c>] panic+0x96/0x1a2
[  142.316300]  [<ffffffff8105cb54>] put_cred_rcu+0x32/0x91
[  142.316306]  [<ffffffff8157a44f>] rcu_do_batch+0xcb/0x1e4
[  142.316313]  [<ffffffff81092967>] invoke_rcu_callbacks+0x6c/0xc7
[  142.316319]  [<ffffffff810932f8>] __rcu_process_callbacks+0x118/0x124
[  142.316325]  [<ffffffff810934f0>] rcu_process_callbacks+0x64/0x72
[  142.316331]  [<ffffffff8103f8c4>] __do_softirq+0x110/0x278
[  142.316338]  [<ffffffff815a23ac>] call_softirq+0x1c/0x30
[  142.316342]  <EOI>  [<ffffffff81003647>] do_softirq+0x44/0xf1
[  142.316352]  [<ffffffff8103f485>] _local_bh_enable_ip+0x12a/0x178
[  142.316358]  [<ffffffff8103f4dc>] local_bh_enable_ip+0x9/0xb
[  142.316364]  [<ffffffff8159a2f3>] _raw_write_unlock_bh+0x36/0x3a
[  142.316372]  [<ffffffff814c1ac3>] unix_release_sock+0x86/0x1ff
[  142.316378]  [<ffffffff8105b548>] ? up_read+0x1b/0x32
[  142.316383]  [<ffffffff814c1c5d>] unix_release+0x21/0x23
[  142.316390]  [<ffffffff81423d02>] sock_release+0x1a/0x6f
[  142.316395]  [<ffffffff81424a30>] sock_close+0x22/0x26
[  142.316401]  [<ffffffff810fcacb>] __fput+0x140/0x1fe
[  142.316407]  [<ffffffff810f97cb>] ? sys_close+0xe6/0x158
[  142.316412]  [<ffffffff810fcb9e>] fput+0x15/0x17
[  142.316417]  [<ffffffff810f8ef2>] filp_close+0x87/0x93
[  142.316422]  [<ffffffff810f97d6>] sys_close+0xf1/0x158
[  142.316429]  [<ffffffff815a0ffb>] system_call_fastpath+0x16/0x1b

Example 2: another RCU botch, but different traceback - probably the most common variant I hit, at least 5-6 times.

[  224.109024] Kernel panic - not syncing: CRED: put_cred_rcu() sees ffff880114888e00 with usage -27
[  224.109026] 
[  224.109041] Pid: 10, comm: ksoftirqd/1 Tainted: G        W   3.1.0-rc4-next-20110831-00001-gf3a20c5-dirty #18
[  224.109045] Call Trace:
[  224.109055]  [<ffffffff81577aac>] panic+0x96/0x1a2
[  224.109063]  [<ffffffff8105cb54>] put_cred_rcu+0x32/0x91
[  224.109069]  [<ffffffff8157a48f>] rcu_do_batch+0xcb/0x1e4
[  224.109075]  [<ffffffff81092967>] invoke_rcu_callbacks+0x6c/0xc7
[  224.109081]  [<ffffffff810932f8>] __rcu_process_callbacks+0x118/0x124
[  224.109087]  [<ffffffff810934f0>] rcu_process_callbacks+0x64/0x72
[  224.109093]  [<ffffffff8103f8c4>] __do_softirq+0x110/0x278
[  224.109098]  [<ffffffff8103faeb>] ? run_ksoftirqd+0xbf/0x20e
[  224.109103]  [<ffffffff8103fafc>] run_ksoftirqd+0xd0/0x20e
[  224.109109]  [<ffffffff8103fa2c>] ? __do_softirq+0x278/0x278
[  224.109115]  [<ffffffff810570d6>] kthread+0x7f/0x87
[  224.109122]  [<ffffffff815a22f4>] kernel_thread_helper+0x4/0x10
[  224.109129]  [<ffffffff8159aea1>] ? retint_restore_args+0xe/0xe
[  224.109135]  [<ffffffff81057057>] ? __init_kthread_worker+0x55/0x55
[  224.109141]  [<ffffffff815a22f0>] ? gs_change+0xb/0xb

Example 3:

[   83.816051] BUG: unable to handle kernel NULL pointer dereference at 0000000000000008
[   83.816069] IP: [<ffffffff8123c1fc>] __list_del_entry+0x144/0x1ab
[   83.816081] PGD 116ba3067 PUD 114ae9067 PMD 0 
[   83.816093] Oops: 0000 [#1] PREEMPT SMP 

[   83.816129] Pid: 1, comm: systemd Tainted: G        W   3.1.0-rc4-next-20110831-dirty #17 Dell Inc. Latitude E6500                /      
[   83.816141] RIP: 0010:[<ffffffff8123c1fc>]  [<ffffffff8123c1fc>] __list_del_entry+0x144/0x1ab
[   83.816150] RSP: 0018:ffff88011f095e58  EFLAGS: 00010246
[   83.816154] RAX: ffff88011fa0edc0 RBX: ffff8800d278c5c0 RCX: 0000000000000061
[   83.816157] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff81ae1640
[   83.816161] RBP: ffff88011f095e88 R08: dead000000200200 R09: 0000000000000000
[   83.816166] R10: ffff8800d278c5d0 R11: ffff8800d278c5c0 R12: 0000000000000000
[   83.816170] R13: 0000000000000000 R14: ffff88011fa19bc0 R15: ffff8801131c9358
[   83.816174] FS:  00007fe3ca2077e0(0000) GS:ffff88011fa00000(0000) knlGS:0000000000000000
[   83.816179] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   83.816183] CR2: 0000000000000008 CR3: 0000000116a3a000 CR4: 00000000000406f0
[   83.816187] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   83.816191] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[   83.816196] Process systemd (pid: 1, threadinfo ffff88011f094000, task ffff88011f092040)
[   83.816200] Stack:
[   83.816203]  ffff88011f095e88 dead000000200200 ffff8800d278c5c0 0000000000000000
[   83.816218]  ffff8801131ce4a0 ffff8801131ce4a0 ffff88011f095ea8 ffffffff810fc94a
[   83.816233]  ffffffff8160c400 ffff8800d278c5c0 ffff88011f095ef8 ffffffff810fcb43
[   83.816247] Call Trace:
[   83.816255]  [<ffffffff810fc94a>] file_sb_list_del+0x1e/0x31
[   83.816261]  [<ffffffff810fcb43>] __fput+0x1b8/0x1fe
[   83.816267]  [<ffffffff810f97cb>] ? sys_close+0xe6/0x158
[   83.816272]  [<ffffffff810fcb9e>] fput+0x15/0x17
[   83.816277]  [<ffffffff810f8ef2>] filp_close+0x87/0x93
[   83.816283]  [<ffffffff810f97d6>] sys_close+0xf1/0x158
[   83.816289]  [<ffffffff815a0ffb>] system_call_fastpath+0x16/0x1b
[   83.816294] Code: 35 00 00 00 48 c7 c7 a1 69 8b 81 31 c0 e8 0a d5 df ff 31 d2 44 89 e6 48 c7 c7 40 16 ae 81 e8 5c 6f e6 ff 45 85 e4 75 5f 45 31 e4 
[   83.816402]  39 5d 08 48 c7 c7 68 16 ae 81 41 0f 95 c4 31 d2 44 89 e6 e8 
[   83.816457] RIP  [<ffffffff8123c1fc>] __list_del_entry+0x144/0x1ab
[   83.816464]  RSP <ffff88011f095e58>
[   83.816469] CR2: 0000000000000008
[   83.816481] ---[ end trace 86b3a584f3090560 ]---

(after which we hit a bunch of "scheduling while atomic" before the other processor grinds to a halt:

Example 4:

[  171.035508] dell_wmi: Received unknown WMI event (0x11)
[  171.345340] general protection fault: 0000 [#1] PREEMPT SMP 
[  171.346608] CPU 1 
[  171.346608] Pid: 2501, comm: polkit-gnome-au Tainted: G        W   3.1.0-rc4-next-20110831-dirty #17 Dell Inc. Latitude E6500                  /      
[  171.346608] RIP: 0010:[<ffffffff81054203>]  [<ffffffff81054203>] free_pid+0x32/0x93
[  171.346608] RSP: 0018:ffff8800d2d65c68  EFLAGS: 00010046
[  171.346608] RAX: 0000000000000096 RBX: ffff8801156db740 RCX: ffff8801156db780
[  171.346608] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[  171.346608] RBP: ffff8800d2d65c78 R08: dead000000200200 R09: 0000000000000001
[  171.346608] R10: 0000000000000000 R11: ffff880037bf86a0 R12: ffff8801145be3c0
[  171.346608] R13: 0000000000000000 R14: ffff880116804580 R15: ffff880116804d88
[  171.346608] FS:  00007f11f74f7700(0000) GS:ffff88011fb00000(0000) knlGS:0000000000000000
[  171.346608] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  171.346608] CR2: 0000000001eb7ee0 CR3: 0000000001a23000 CR4: 00000000000406e0
[  171.346608] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  171.346608] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  171.346608] Process polkit-gnome-au (pid: 2501, threadinfo ffff8800d2d64000, task ffff8800d2d627c0)
[  171.346608] Stack:
[  171.346608]  ffff8800d2d627c0 ffff8801145be3c0 ffff8800d2d65c88 ffffffff810542b9
[  171.346608]  ffff8800d2d65c98 ffffffff81054442 ffff8800d2d65ce8 ffffffff8157801f
[  171.346608]  ffffffff00000000 0000000000000000 ffff8800d2d65ce8 ffff8800d2d627c0
[  171.346608] Call Trace:
[  171.346608]  [<ffffffff810542b9>] __change_pid+0x55/0x57
[  171.346608]  [<ffffffff81054442>] detach_pid+0xb/0xd
[  171.346608]  [<ffffffff8157801f>] __exit_signal+0x1e4/0x2d4
[  171.346608]  [<ffffffff8103bdcc>] release_task+0xf1/0x186
[  171.346608]  [<ffffffff81578418>] exit_notify+0x171/0x17a
[  171.346608]  [<ffffffff8103d16b>] do_exit+0x458/0x4f5
[  171.346608]  [<ffffffff810a299b>] ? trace_preempt_on+0x15/0x28
[  171.346608]  [<ffffffff8103d3dd>] do_group_exit+0x9e/0xcb
[  171.346608]  [<ffffffff8104bc3a>] get_signal_to_deliver+0x469/0x4aa
[  171.346608]  [<ffffffff81001c6d>] do_signal+0x31/0xe9
[  171.346608]  [<ffffffff81067ca2>] ? lockdep_init_map.part.9+0x47/0xb2
[  171.346608]  [<ffffffff810f9908>] ? fd_install+0xcb/0xd8
[  171.346608]  [<ffffffff810a299b>] ? trace_preempt_on+0x15/0x28
[  171.346608]  [<ffffffff810f9908>] ? fd_install+0xcb/0xd8
[  171.346608]  [<ffffffff8159a75c>] ? _raw_spin_unlock+0x2d/0x66
[  171.346608]  [<ffffffff8159db56>] ? sub_preempt_count+0x33/0x46
[  171.346608]  [<ffffffff810a2943>] ? time_hardirqs_on+0x1b/0x2f
[  171.346608]  [<ffffffff815a1081>] ? sysret_signal+0x5/0x47
[  171.346608]  [<ffffffff81001e8d>] do_notify_resume+0x27/0x5c
[  171.346608]  [<ffffffff8123607e>] ? trace_hardirqs_on_thunk+0x3a/0x3f
[  171.346608]  [<ffffffff815a1318>] int_signal+0x12/0x17
[  171.346608] Code: 48 89 fb 48 c7 c7 40 41 a0 81 e8 7f 60 54 00 31 d2 eb 31 48 63 ca 48 83 c1 02 48 c1 e1 05 48 01 d9 48 8b 39 4c 8b 41 08 48 85 ff 
[  171.346608]  89 38 74 04 4c 89 47 08 49 bb 00 02 20 00 00 00 ad de ff c2 
[  171.346608] RIP  [<ffffffff81054203>] free_pid+0x32/0x93
[  171.346608]  RSP <ffff8800d2d65c68>
[  171.346608] ---[ end trace 403d5ef3a1ab950e ]---
[  171.346608] Fixing recursive fault but reboot is needed!

and then the other CPU catches a hard lockup error.

YES, I can confirm this with next-20110826.

I saw similiar call-traces with put_cred_rcu() - besides with kmem_cache_alloc_trace().
My post-it says:

Kernel panic - not syncing: CRED: put_cred_rcu sees f67ac0c0 with usage -43

BTW, systemd (uses dbus/sockets) is more sensitive than Debian's standard sysvinit.

- Sedat -

Hm, Tim, it looks like you put a pid which you did not get?

regards,

js

The skb can be destructed before the while loop in unix_stream_sendmsg stops. please try below patch.

---

index e6d9d10..f6d7ed7 100644
@@ -1577,6 +1577,7 @@ static int unix_stream_sendmsg(struct kiocb

*kiocb, struct socket *sock,
int sent = 0;
struct scm_cookie tmp_scm;
bool fds_sent = false;
+ bool scm_ref = true;
int max_level;

if (NULL == siocb->scm)
@@ -1637,12 +1638,19 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
*/
size = min_t(int, size, skb_tailroom(skb));

+ /*
+ * pass the scm reference to the skb if a single skb is large
+ * enough to hold all data.
+ */
+ if (!fds_sent && sent + size >= len)
+ scm_ref = false;

- /* Only send the fds and no ref to pid in the first buffer */
- err = unix_scm_to_skb(siocb->scm, skb, !fds_sent, fds_sent);
+ /* Only send the fds in the first buffer */
+ err = unix_scm_to_skb(siocb->scm, skb, !fds_sent,
+ fds_sent || scm_ref);
if (err < 0) {
kfree_skb(skb);
- goto out;
+ goto out_err;
}
max_level = err + 1;
fds_sent = true;
@@ -1650,7 +1658,7 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
err = memcpy_fromiovec(skb_put(skb, size), msg->msg_iov, size); if (err) {
kfree_skb(skb);
- goto out;
+ goto out_err;
}

unix_state_lock(other);
@@ -1667,10 +1675,10 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
sent += size;
}

- if (skb)
- scm_release(siocb->scm);
- else
+ if (scm_ref)
scm_destroy(siocb->scm);
+ else
+ scm_release(siocb->scm);
siocb->scm = NULL;

return sent;
@@ -1683,9 +1691,10 @@ pipe_err:
send_sig(SIGPIPE, current, 0);
err = -EPIPE;
out_err:
- if (skb == NULL)
+ if (scm_ref)
scm_destroy(siocb->scm);
-out:
+ else
+ scm_release(siocb->scm);
siocb->scm = NULL;
return sent ? : err;
}

I have tested your patch on i386 against:

1. linux-next/patch-v3.1-rc3-next-20110826
2. scm-fix/0001-Revert-Scm-Remove-unnecessary-pid-credential-referen.patch
3. scm-fix-2/scm_send.patch
4. scm-fix-3/0001-Fix-unix-stream-crashes.patch

So the BROKEN scm-send path seems to be fixed, now!

As the patch arrived "malformed" in my mbox I git-am-ed it on top of linux-next (next-20110826) GIT repository (patch attached).

After confirmation of Valdis (x86_64) and ACK-by Tim, I would appreciate a proper patch with all Reported-by/Tested-by/S-o-b etc. In my case I bisected the issue, I recall that there is sth. like Bisected-by, so feel free to do so.

Doing now a 2nd run with:

1. linux-next/patch-v3.1-rc3-next-20110826
2. scm-fix-3/0001-Fix-unix-stream-crashes.patch

- Sedat -

From 54d8a5c590c06f070d9adbfffba0b32246d727e2 Mon Sep 17 00:00:00 2001
From: "Yan, Zheng" <[email protected]>
Date: Sat, 3 Sep 2011 14:30:19 +0200
Subject: [PATCH] Fix unix stream crashes

The skb can be destructed before the while loop in unix_stream_sendmsg stops. please try below patch.

---
 net/unix/af_unix.c |   27 ++++++++++++++++++---------
 1 files changed, 18 insertions(+), 9 deletions(-)

index e6d9d10..f6d7ed7 100644
@@ -1577,6 +1577,7 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 	int sent = 0;
 	struct scm_cookie tmp_scm;
 	bool fds_sent = false;
+	bool scm_ref = true;
 	int max_level;
 
 	if (NULL == siocb->scm)

@@ -1637,12 +1638,19 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 		 */
 		size = min_t(int, size, skb_tailroom(skb));
 
+		/*
+		 * pass the scm reference to the skb if a single skb is large
+		 * enough to hold all data.
+		 */
+		if (!fds_sent && sent + size >= len)
+			scm_ref = false;
 
-		/* Only send the fds and no ref to pid in the first buffer */
-		err = unix_scm_to_skb(siocb->scm, skb, !fds_sent, fds_sent);
+		/* Only send the fds in the first buffer */
+		err = unix_scm_to_skb(siocb->scm, skb, !fds_sent,
+					fds_sent || scm_ref);
 		if (err < 0) {
 			kfree_skb(skb);
-			goto out;
+			goto out_err;
 		}
 		max_level = err + 1;
 		fds_sent = true;

@@ -1650,7 +1658,7 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 		err = memcpy_fromiovec(skb_put(skb, size), msg->msg_iov, size);
 		if (err) {
 			kfree_skb(skb);
-			goto out;
+			goto out_err;
 		}
 
 		unix_state_lock(other);

@@ -1667,10 +1675,10 @@ static int unix_stream_sendmsg(struct kiocb *kiocb, struct socket *sock,
 		sent += size;
 	}
 
-	if (skb)
-		scm_release(siocb->scm);
-	else
+	if (scm_ref)
 		scm_destroy(siocb->scm);
+	else
+		scm_release(siocb->scm);
 	siocb->scm = NULL;
 
 	return sent;

@@ -1683,9 +1691,10 @@ pipe_err:
 		send_sig(SIGPIPE, current, 0);
 	err = -EPIPE;
 out_err:
-	if (skb == NULL)
+	if (scm_ref)
 		scm_destroy(siocb->scm);
-out:
+	else
+		scm_release(siocb->scm);
 	siocb->scm = NULL;
 	return sent ? : err;
 }

1.7.6

[...]

[...]

2nd run is fine, too.

- Sedat -

Thank you, will send a new patch later.

Tried this on top of next-20110831, and system is up and running fine.

Feel free to stick this on it: