CURRENT + amd64 + user-ppp = panic
Victor Snezhko
snezhko at indorsoft.ru
Tue Nov 8 12:52:52 PST 2005
Victor Snezhko <snezhko at indorsoft.ru> writes:
>> Tomorrow I'll try to trace all callout-related operations in nd6
>> and/or the whole netinet6.
>
> Hmmm... trace shows that the callout_stop/callout_drain call
> always receives a pointer that has not been initialized via
> callout_init, at least not in /usr/src/sys/netinet6/*
Sorry, I lied here. Details below.
> I'll debug this further and report the results.
Hmm, debugging was not so fast...
So, here is what I have for the moment:
1) I was dead wrong about stop called on a pointer that was not
initialized(there was a typo in one of my printf's).
Call trace shows the following:
At first, nd6_rtrequest(RTM_ADD) is called, it calls callout_init on
the timer and then callout_stop (through nd6_llinfo_settimer).
Then nd6_rtrequest(RTM_DELETE) is called, and it calls callout_stop
without callout_init.
This seemed to be one of the possible cause of the problem, but when
I commented out the last call to nd6_llinfo_settimer(ln, -1), nothing
changed.
2) I tried to trace where corruption occurs. In order to do this I
inserted slow checks into all the code in kern_timeout.c that could
modify the callwheel. No success - first 0xdeadc0de's were
detected by softclock(), not by any other call.
Here is the corresponding patch:
-------------- next part --------------
A non-text attachment was scrubbed...
Name: kern_timeout.diff
Type: text/x-patch
Size: 4215 bytes
Desc: not available
Url : http://lists.freebsd.org/pipermail/freebsd-current/attachments/20051109/a94e6b4a/kern_timeout.bin
-------------- next part --------------
pointer comparisons are probably not 64bit-clean, correct me please if
those pointer->int casts are bad.
If the backtrace is needed I can provide it, just ask.
My check triggers panic when called from a softclock().
3) Recently, thanks to Mark Tinguely, I have found out that I could do
additional checks in trash_dtor() in uma_dbg.c
No results again.
I inserted the following check:
-------------- next part --------------
A non-text attachment was scrubbed...
Name: uma_dbg.diff
Type: text/x-patch
Size: 1011 bytes
Desc: not available
Url : http://lists.freebsd.org/pipermail/freebsd-current/attachments/20051109/a94e6b4a/uma_dbg.bin
-------------- next part --------------
(Again not quite 64bit-ready, the same nasty pointer casts)
Here is the backtrace:
-------------- next part --------------
/var/crash # kgdb /usr/obj/usr/src/sys/VVS/kernel vmcore.24
[... skipped ...]
Unread portion of the kernel message buffer:
KDB: enter: trash_dtor: uma_junk found in a callwheel element
panic: from debugger
cpuid = 0
Uptime: 4m2s
Dumping 63 MB (3 chunks)
chunk 0: 1MB (159 pages) ... ok
chunk 1: 62MB (15856 pages) 46 30 14 ... ok
chunk 2: 1MB (256 pages)
#0 doadump () at pcpu.h:165
165 pcpu.h: No such file or directory.
in pcpu.h
(kgdb) bt
#0 doadump () at pcpu.h:165
#1 0xc0660824 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:399
#2 0xc0660b39 in panic (fmt=0xc0856fa0 "from debugger")
at /usr/src/sys/kern/kern_shutdown.c:555
#3 0xc046cee1 in db_panic (addr=-1066954485, have_addr=0, count=-1,
modif=0xc60ac934 "") at /usr/src/sys/ddb/db_command.c:434
#4 0xc046ce78 in db_command (last_cmdp=0xc0947a84, cmd_table=0x0,
aux_cmd_tablep=0xc08bda78, aux_cmd_tablep_end=0xc08bda94)
at /usr/src/sys/ddb/db_command.c:403
#5 0xc046cf40 in db_command_loop () at /usr/src/sys/ddb/db_command.c:454
#6 0xc046eb59 in db_trap (type=3, code=0) at /usr/src/sys/ddb/db_main.c:221
#7 0xc06793a4 in kdb_trap (type=3, code=0, tf=0xc60acacc)
at /usr/src/sys/kern/subr_kdb.c:473
#8 0xc0821630 in trap (frame=
{tf_fs = 8, tf_es = 40, tf_ds = 40, tf_edi = -1053265664, tf_esi = -1053265920, tf_ebp = -972371188, tf_isp = -972371208, tf_ebx = -559038242, tf_edx = 0, tf_ecx = -1056755712, tf_eax = 62, tf_trapno = 3, tf_err = 0, tf_eip = -1066954485, tf_cs = 32, tf_eflags = 646, tf_esp = -972371156, tf_ss = -1065665882}) at /usr/src/sys/i386/i386/trap.c:610
#9 0xc080ecba in calltrap () at /usr/src/sys/i386/i386/exception.s:139
#10 0xc067910b in kdb_enter (msg=0x3e <Address 0x3e out of bounds>)
---Type <return> to continue, or q <return> to quit---
at cpufunc.h:60
#11 0xc07b3aa6 in trash_dtor (mem=0xc1387000, size=256, arg=0x0)
at /usr/src/sys/vm/uma_dbg.c:104
#12 0xc0657dd8 in mb_dtor_mbuf (mem=0xc1387000, size=256, arg=0x0)
at /usr/src/sys/kern/kern_mbuf.c:245
#13 0xc07b23e4 in uma_zfree_arg (zone=0xc1042960, item=0xc1387000, udata=0x0)
at /usr/src/sys/vm/uma_core.c:2270
#14 0xc069b9ba in soreceive (so=0xc143d9bc, psa=0xc60acbe8, uio=0xc60acbf4,
mp0=0x0, controlp=0x0, flagsp=0xc60acc74) at uma.h:303
#15 0xc06a08c7 in kern_recvit (td=0xc12f3320, s=5, mp=0xc60acc5c,
namelenp=0xbfbfdacc, segflg=62) at /usr/src/sys/kern/uipc_syscalls.c:986
#16 0xc06a0af6 in recvit (td=0xc12f3320, s=5, mp=0xc60acc5c,
namelenp=0xbfbfdacc) at /usr/src/sys/kern/uipc_syscalls.c:1094
#17 0xc06a0b64 in recvfrom (td=0xc12f3320, uap=0xc60acd04)
at /usr/src/sys/kern/uipc_syscalls.c:1131
#18 0xc0821e96 in syscall (frame=
{tf_fs = 59, tf_es = 59, tf_ds = 59, tf_edi = 134570084, tf_esi = 134570080, tf_ebp = -1077940616, tf_isp = -972370588, tf_ebx = 134546020, tf_edx = -1077940864, tf_ecx = 5, tf_eax = 29, tf_trapno = 32, tf_err = 2, tf_eip = 672166495, tf_cs = 51, tf_eflags = 66198, tf_esp = -1077945812, tf_ss = 59})
at /usr/src/sys/i386/i386/trap.c:1001
---Type <return> to continue, or q <return> to quit---
#19 0xc080ed0f in Xint0x80_syscall ()
at /usr/src/sys/i386/i386/exception.s:200
#20 0x00000033 in ?? ()
Previous frame inner to this frame (corrupt stack?)
(kgdb) up 11
#11 0xc07b3aa6 in trash_dtor (mem=0xc1387000, size=256, arg=0x0)
at /usr/src/sys/vm/uma_dbg.c:104
104 kdb_enter("trash_dtor: uma_junk found in a "\
(kgdb) list
99 for (c = TAILQ_FIRST(bucket); c != NULL;
100 c = TAILQ_NEXT(c, c_links.tqe)) {
101 int c2 = (int)c;
102 int mem2 = (int)mem;
103 if ((u_int32_t)c == uma_junk) {
104 kdb_enter("trash_dtor: uma_junk found in a "\
105 "callwheel element");
106 break;
107 }
108 if (c2 >= mem2 && c2 < mem2 + size) {
(kgdb) up 1
#12 0xc0657dd8 in mb_dtor_mbuf (mem=0xc1387000, size=256, arg=0x0)
at /usr/src/sys/kern/kern_mbuf.c:245
245 trash_dtor(mem, size, arg);
(kgdb) list
240
241 m = (struct mbuf *)mem;
242 if ((m->m_flags & M_PKTHDR) != 0)
243 m_tag_delete_chain(m, NULL);
244 #ifdef INVARIANTS
245 trash_dtor(mem, size, arg);
246 #endif
247 }
248
249 /* XXX Only because of stats */
(kgdb) up 1
#13 0xc07b23e4 in uma_zfree_arg (zone=0xc1042960, item=0xc1387000, udata=0x0)
at /usr/src/sys/vm/uma_core.c:2270
2270 zone->uz_dtor(item, keg->uk_size, udata);
(kgdb) list
2265 #endif
2266 CTR2(KTR_UMA, "uma_zfree_arg thread %x zone %s", curthread,
2267 zone->uz_name);
2268
2269 if (zone->uz_dtor)
2270 zone->uz_dtor(item, keg->uk_size, udata);
2271 #ifdef INVARIANTS
2272 ZONE_LOCK(zone);
2273 if (keg->uk_flags & UMA_ZONE_MALLOC)
2274 uma_dbg_free(zone, udata, item);
(kgdb) up 1
#14 0xc069b9ba in soreceive (so=0xc143d9bc, psa=0xc60acbe8, uio=0xc60acbf4,
mp0=0x0, controlp=0x0, flagsp=0xc60acc74) at uma.h:303
303 uma_zfree_arg(zone, item, NULL);
(kgdb) list
298 static __inline void uma_zfree(uma_zone_t zone, void *item);
299
300 static __inline void
301 uma_zfree(uma_zone_t zone, void *item)
302 {
303 uma_zfree_arg(zone, item, NULL);
304 }
305
306 /*
307 * XXX The rest of the prototypes in this header are h0h0 magic for the VM.
(kgdb) up 1
#15 0xc06a08c7 in kern_recvit (td=0xc12f3320, s=5, mp=0xc60acc5c,
namelenp=0xbfbfdacc, segflg=62) at /usr/src/sys/kern/uipc_syscalls.c:986
986 error = so->so_proto->pr_usrreqs->pru_soreceive(so, &fromsa, &auio,
(kgdb) list
981 #ifdef KTRACE
982 if (KTRPOINT(td, KTR_GENIO))
983 ktruio = cloneuio(&auio);
984 #endif
985 len = auio.uio_resid;
986 error = so->so_proto->pr_usrreqs->pru_soreceive(so, &fromsa, &auio,
987 (struct mbuf **)0, mp->msg_control ? &control : (struct mbuf **)0,
988 &mp->msg_flags);
989 if (error) {
990 if (auio.uio_resid != (int)len && (error == ERESTART ||
(kgdb) print *(so->so_proto->pr_usrreqs)
$5 = {__Break_the_struct_layout_for_now = 0,
pru_abort = 0xc06a24ec <uipc_abort>, pru_accept = 0xc06a2600 <uipc_accept>,
pru_attach = 0xc06a26b4 <uipc_attach>, pru_bind = 0xc06a26d0 <uipc_bind>,
pru_connect = 0xc06a2740 <uipc_connect>,
pru_connect2 = 0xc06a27c8 <uipc_connect2>,
pru_control = 0xc069f300 <pru_control_notsupp>,
pru_detach = 0xc06a2838 <uipc_detach>,
pru_disconnect = 0xc06a28a0 <uipc_disconnect>,
pru_listen = 0xc06a2908 <uipc_listen>,
pru_peeraddr = 0xc06a2980 <uipc_peeraddr>,
pru_rcvd = 0xc06a2a34 <uipc_rcvd>,
pru_rcvoob = 0xc069f348 <pru_rcvoob_notsupp>,
pru_send = 0xc06a2bc4 <uipc_send>, pru_sense = 0xc06a3024 <uipc_sense>,
pru_shutdown = 0xc06a30f0 <uipc_shutdown>,
pru_sockaddr = 0xc06a3168 <uipc_sockaddr>,
pru_sosend = 0xc069ad84 <sosend>, pru_soreceive = 0xc069b5b0 <soreceive>,
pru_sopoll = 0xc069d090 <sopoll>,
pru_sosetlabel = 0xc069f3b8 <pru_sosetlabel_null>}
(kgdb) up 1
#16 0xc06a0af6 in recvit (td=0xc12f3320, s=5, mp=0xc60acc5c,
namelenp=0xbfbfdacc) at /usr/src/sys/kern/uipc_syscalls.c:1094
1094 return (kern_recvit(td, s, mp, namelenp, UIO_USERSPACE));
(kgdb) list
1089 int s;
1090 struct msghdr *mp;
1091 void *namelenp;
1092 {
1093
1094 return (kern_recvit(td, s, mp, namelenp, UIO_USERSPACE));
1095 }
1096
1097 /*
1098 * MPSAFE
-------------- next part --------------
The thing I want to note is that callwheel corruptions after applying
this patch stop to be reproducible. They may occur, may not.
4) I inserted a kdb_enter() call in the beginning of
nd6_llinfo_settimer(). Then tried to step some functions up the
stack. Pressed "n" a couple of times, then exit via "c". Panic didn't
occur! (It would certainly occur if I exited the kdb immediately after
kdb_enter).
Don't know what to think about the last. Improper locking? Freeing a
callwheel entry and then it's slow removal? Strange...
P.S.: Perharps I should file a PR about all this as the problem turned
out to be not so easy. To what degree should I include the details
above?
--
WBR, Victor V. Snezhko
EMail: snezhko at indorsoft.ru
More information about the freebsd-current
mailing list