Bug 51813 - Tomcat randomly crashes with [libtcnative-1.so.1+0x152ca] Java_org_apache_tomcat_jni_Socket_sendbb+0x5a
Summary: Tomcat randomly crashes with [libtcnative-1.so.1+0x152ca] Java_org_apache_to...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat Native
Classification: Unclassified
Component: Library (show other bugs)
Version: 1.1.22
Hardware: PC FreeBSD
: P2 critical (vote)
Target Milestone: ---
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-09-14 20:25 UTC by Mike Jakubik
Modified: 2014-02-17 13:45 UTC (History)
0 users



Attachments
Patch against tcnative-1.1.x (4.00 KB, patch)
2013-06-06 16:20 UTC, Christopher Schultz
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Mike Jakubik 2011-09-14 20:25:06 UTC
Hello,

After a recent upgrade of tomcat-native and apr1, tomcat crashes about once a day with the following error.

FreeBSD 8.2-STABLE #0: Mon Sep 12 16:17:30 EDT 2011

apr-devrandom-1.4.5.1.3.12_1
openjdk6-b23_1
tomcat-6.0.33_1
tomcat-native-1.1.22

Thanks.


---
Memory: 4k page, physical 3738444k(934611k free)

/proc/meminfo:


vm_info: OpenJDK 64-Bit Server VM (20.0-b11) for bsd-amd64 JRE (1.6.0-b23), built on Sep 12 2011 16:30:25 by "root" with gcc 4.2.2 20070831 prerelease [FreeBSD]

time: Wed Sep 14 15:37:34 2011
elapsed time: 96332 seconds

diversity@app.local:~$ cat hs_err_pid11416.log 
diversity@app.local:~$ cat hs_err_pid11416.log 
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00000008e711c2ca, pid=11416, tid=34389419648
#
# JRE version: 6.0-b23
# Java VM: OpenJDK 64-Bit Server VM (20.0-b11 mixed mode bsd-amd64 compressed oops)
# Problematic frame:
# C  [libtcnative-1.so.1+0x152ca]  Java_org_apache_tomcat_jni_Socket_sendbb+0x5a
#
# If you would like to submit a bug report, please visit:
#   http://java.sun.com/webapps/bugreport/crash.jsp
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#

---------------  T H R E A D  ---------------

Current thread (0x0000000801cee800):  JavaThread "Finalizer" daemon [_thread_in_native, id=100137, stack(0x00007fffff3f8000,0x00007fffff4f8000)]

siginfo:si_signo=SIGSEGV: si_errno=0, si_code=1 (SEGV_MAPERR), si_addr=0x0000000000000040

Registers:
RAX=0x0000000000000000, RBX=0x0000000000000000, RCX=0x0000000000000000, RDX=0x00007fffff4f6f88
RSP=0x00007fffff4f6f80, RBP=0x00000008eea0d0a0, RSI=0x0000000000000000, RDI=0x0000000000000000
R8 =0x000000000000000e, R9 =0x000000080c848858, R10=0x0000000802151d3b, R11=0x000000080158d150
R12=0x000000000000000e, R13=0x0000000000000000, R14=0x00007fffff4f6f88, R15=0x0000000801cee800
RIP=0x00000008e711c2ca, EFLAGS=0x0000000000000001, ERR=0x0000000000000004
  TRAPNO=0x000000000000000c

Top of Stack: (sp=0x00007fffff4f6f80)
0x00007fffff4f6f80:   00000008037c6ebc 000000000000000e
0x00007fffff4f6f90:   0000000805b2a308 00007fffff4f7028
0x00007fffff4f6fa0:   000000080515f000 0000000805b2a308
0x00007fffff4f6fb0:   00007fffff4f7060 0000000802151d68
0x00007fffff4f6fc0:   0000000007d4c462 0000000843bc1430
0x00007fffff4f6fd0:   0000000843b9e0e8 07d4b5d600000000
0x00007fffff4f6fe0:   0000000843bad168 00007fffff4f6fe8
0x00007fffff4f6ff0:   0000000000000000 00007fffff4f7060
0x00007fffff4f7000:   0000000805b2b660 0000000000000000
0x00007fffff4f7010:   0000000805b2a308 0000000000000000
0x00007fffff4f7020:   00007fffff4f7070 00007fffff4f7158
0x00007fffff4f7030:   0000000803a2d280 0000000805b2b5f8
0x00007fffff4f7040:   000000080214ef56 000000080000000e
0x00007fffff4f7050:   00007fff00000000 00000008eea0d0a0
0x00007fffff4f7060:   00000008f6d410a0 0000000803a2d280
0x00007fffff4f7070:   0000000843bad168 00007fffff4f7090
0x00007fffff4f7080:   00007fffff4f70e8 000000080214685a
0x00007fffff4f7090:   00007fffff4f7100 000000080214685a
0x00007fffff4f70a0:   00007fffff4f7158 0000000803be86f0
0x00007fffff4f70b0:   0000000829fbb1f0 0000000843bb9e58
0x00007fffff4f70c0:   00007fffff4f70c0 000000080c841ecd
0x00007fffff4f70d0:   00007fffff4f7110 000000080c843338
0x00007fffff4f70e0:   00007fffff4f7158 000000080214685a
0x00007fffff4f70f0:   00007fffff4f7158 000000080214685a
0x00007fffff4f7100:   0000000843bb9e58 0000000829fbb1e0
0x00007fffff4f7110:   0000000843bb9e58 00007fffff4f7118
0x00007fffff4f7120:   000000080c870e40 00007fffff4f7178
0x00007fffff4f7130:   000000080c872b98 0000000812603d80
0x00007fffff4f7140:   000000080c870e98 00007fffff4f7100
0x00007fffff4f7150:   00007fffff4f7170 00007fffff4f71c0
0x00007fffff4f7160:   000000080214685a 0000000000000000
0x00007fffff4f7170:   0000000000000001 0000000843bba248 

Instructions: (pc=0x00000008e711c2ca)
0x00000008e711c2aa:   4c 89 f2 4c 89 e0 4c 89 ee 48 29 d8 48 89 44 24
0x00000008e711c2ba:   08 48 03 75 20 48 8b 45 30 48 01 de 48 8b 7d 18
0x00000008e711c2ca:   ff 50 40 89 c2 85 c0 74 cd 3d 77 11 01 00 74 47
0x00000008e711c2da:   be 3e 2b fe ff 83 fa 23 74 1d 40 b6 3d 83 fa 04 

Register to memory mapping:

RAX=0x0000000000000000 is an unknown value
RBX=0x0000000000000000 is an unknown value
RCX=0x0000000000000000 is an unknown value
RDX=0x00007fffff4f6f88 is pointing into the stack for thread: 0x0000000801cee800
RSP=0x00007fffff4f6f80 is pointing into the stack for thread: 0x0000000801cee800
RBP=0x00000008eea0d0a0 is an unknown value
RSI=0x0000000000000000 is an unknown value
RDI=0x0000000000000000 is an unknown value
R8 =0x000000000000000e is an unknown value
R9 =0x000000080c848858 is an oop
{instance class} 
 - klass: {other class}
R10=0x0000000802151d3b is an Interpreter codelet
method entry point (kind = native)  [0x0000000802151ae0, 0x0000000802152320]  2112 bytes
R11=0x000000080158d150: JVM_handle_bsd_signal+0x7d4e0 in /usr/local/openjdk6/jre/lib/amd64/server/libjvm.so at 0x0000000800e00000
R12=0x000000000000000e is an unknown value
R13=0x0000000000000000 is an unknown value
R14=0x00007fffff4f6f88 is pointing into the stack for thread: 0x0000000801cee800
R15=0x0000000801cee800 is a thread


Stack: [0x00007fffff3f8000,0x00007fffff4f8000],  sp=0x00007fffff4f6f80,  free space=1019k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C  [libtcnative-1.so.1+0x152ca]  Java_org_apache_tomcat_jni_Socket_sendbb+0x5a

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  org.apache.tomcat.jni.Socket.sendbb(JII)I+0
J  org.apache.coyote.ajp.AjpAprProcessor.action(Lorg/apache/coyote/ActionCode;Ljava/lang/Object;)V
J  org.apache.coyote.Response.action(Lorg/apache/coyote/ActionCode;Ljava/lang/Object;)V
j  org.apache.catalina.connector.OutputBuffer.doFlush(Z)V+80
j  org.apache.catalina.connector.OutputBuffer.flush()V+2
j  org.apache.catalina.connector.CoyoteOutputStream.flush()V+4
j  javax.imageio.stream.MemoryCacheImageOutputStream.flushBefore(J)V+47
j  javax.imageio.stream.MemoryCacheImageOutputStream.close()V+15
j  javax.imageio.stream.ImageInputStreamImpl.finalize()V+8
v  ~StubRoutines::call_stub
J  java.lang.ref.Finalizer.invokeFinalizeMethod(Ljava/lang/Object;)V
J  java.lang.ref.Finalizer.access$100(Ljava/lang/ref/Finalizer;)V
J  java.lang.ref.Finalizer$FinalizerThread.run()V
v  ~StubRoutines::call_stub

Other Threads:
  0x0000000801d2d800 VMThread [stack: 0x00007fffff5fa000,0x00007fffff6fa000] [id=100135]
  0x0000000801d2d000 WatcherThread [stack: 0x00007ffffeef3000,0x00007ffffeff3000] [id=100156]

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap
 PSYoungGen      total 128640K, used 7850K [0x00000008dd160000, 0x00000008e5160000, 0x00000008e5160000)
  eden space 126208K, 6% used [0x00000008dd160000,0x00000008dd90aa68,0x00000008e4ca0000)
  from space 2432K, 0% used [0x00000008e4ca0000,0x00000008e4ca0000,0x00000008e4f00000)
  to   space 2432K, 0% used [0x00000008e4f00000,0x00000008e4f00000,0x00000008e5160000)
 PSOldGen        total 849152K, used 755229K [0x0000000825160000, 0x0000000858ea0000, 0x00000008dd160000)
  object space 849152K, 88% used [0x0000000825160000,0x00000008532e7738,0x0000000858ea0000)
 PSPermGen       total 289920K, used 288717K [0x0000000805160000, 0x0000000816c80000, 0x0000000825160000)
  object space 289920K, 99% used [0x0000000805160000,0x0000000816b53670,0x0000000816c80000)

Code Cache  [0x0000000802141000, 0x0000000804f11000, 0x0000000805141000)
 total_blobs=9408 nmethods=8841 adapters=519 free_code_cache=2687808 largest_free_block=54272

Dynamic libraries:
0x0000000000400000 	/usr/local/openjdk6/bin/java
0x0000000800650000 	/lib/libz.so.5
0x0000000800765000 	/lib/libthr.so.3
0x000000080087e000 	/lib/libc.so.7
0x0000000800e00000 	/usr/local/openjdk6/jre/lib/amd64/server/libjvm.so
0x000000080188d000 	/usr/lib/libstdc++.so.6
0x0000000800aba000 	/lib/libm.so.5
0x0000000801a9b000 	/lib/libgcc_s.so.1
0x0000000801e00000 	/usr/local/openjdk6/jre/lib/amd64/libverify.so
0x0000000801f0f000 	/usr/local/openjdk6/jre/lib/amd64/libjava.so
0x000000080203a000 	/usr/local/openjdk6/jre/lib/amd64/libzip.so
0x00000008e7000000 	/usr/local/openjdk6/jre/lib/amd64/libmanagement.so
0x00000008e7107000 	/usr/local/lib/libtcnative-1.so.1
0x00000008e7229000 	/usr/lib/libssl.so.6
0x00000008e737c000 	/lib/libcrypto.so.6
0x00000008e761d000 	/usr/local/lib/libapr-1.so.4
0x00000008e7749000 	/lib/libcrypt.so.5
0x00000008e7862000 	/usr/local/openjdk6/jre/lib/amd64/libawt.so
0x00000008e7a2a000 	/usr/local/openjdk6/jre/lib/amd64/headless/libmawt.so
0x00000008e7b30000 	/usr/local/openjdk6/jre/lib/amd64/liblcms.so
0x00000008e7c69000 	/usr/local/openjdk6/jre/lib/amd64/libjpeg.so
0x00000008ebc00000 	/usr/local/openjdk6/jre/lib/amd64/libnet.so
0x00000008efa00000 	/usr/local/openjdk6/jre/lib/amd64/librmi.so
0x00000008f443a000 	/usr/local/openjdk6/jre/lib/amd64/libfontmanager.so
0x00000008f4c00000 	/usr/local/lib/libfreetype.so.9
0x00000008f6800000 	/usr/lib/libbz2.so.4
0x00000008f6910000 	/usr/local/openjdk6/jre/lib/amd64/libnio.so
0x000000080050a000 	/libexec/ld-elf.so.1

VM Arguments:
jvm_args: -Xms512m -Xmx3072m -XX:MaxPermSize=512m -Xmn128m -Duser.language=en -Duser.country=US -Dorg.apache.jasper.compiler.Parser.STRICT_QUOTE_ESCAPING=false -Dnetworkaddress.cache.ttl=3600 -Djava.endorsed.dirs=/usr/local/apache-tomcat-6.0/endorsed -Dcatalina.base=/usr/local/apache-tomcat-6.0 -Dcatalina.home=/usr/local/apache-tomcat-6.0 -Djava.io.tmpdir=/usr/local/apache-tomcat-6.0/temp 
java_command: org.apache.catalina.startup.Bootstrap start
Launcher Type: SUN_STANDARD

Environment Variables:
JAVA_HOME=/usr/local/openjdk6
PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/games:/usr/local/sbin:/usr/local/bin:/home/diversity/bin
USERNAME=root
LD_LIBRARY_PATH=/usr/local/openjdk6/jre/lib/amd64/server:/usr/local/openjdk6/jre/lib/amd64:/usr/local/openjdk6/jre/../lib/amd64
SHELL=/usr/local/bin/bash

Signal Handlers:
SIGSEGV: [libjvm.so+0x860b50], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGBUS: [libjvm.so+0x860b50], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGFPE: [libjvm.so+0x70ae70], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGPIPE: [libjvm.so+0x70ae70], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGXFSZ: [libjvm.so+0x70ae70], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGILL: [libjvm.so+0x70ae70], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGUSR1: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGUSR2: [libjvm.so+0x70d6c0], sa_mask[0]=0x00000000, sa_flags=0x00000042
SIGHUP: [libjvm.so+0x70c170], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGINT: [libjvm.so+0x70c170], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGTERM: [libjvm.so+0x70c170], sa_mask[0]=0xfffefeff, sa_flags=0x00000042
SIGQUIT: [libjvm.so+0x70c170], sa_mask[0]=0xfffefeff, sa_flags=0x00000042


---------------  S Y S T E M  ---------------

OS:Bsd
uname:FreeBSD 8.2-STABLE FreeBSD 8.2-STABLE #0: Mon Sep 12 16:17:30 EDT 2011     root@app.local:/usr/obj/usr/src/sys/APP amd64
rlimit: STACK 524288k, CORE infinity, NPROC 5547, NOFILE 11095
CPU:total 4 (4 cores per cpu, 1 threads per core) family 6 model 23 stepping 6, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1

Memory: 4k page, physical 3738444k(934611k free)

/proc/meminfo:


vm_info: OpenJDK 64-Bit Server VM (20.0-b11) for bsd-amd64 JRE (1.6.0-b23), built on Sep 12 2011 16:30:25 by "root" with gcc 4.2.2 20070831 prerelease [FreeBSD]

time: Wed Sep 14 15:37:34 2011
elapsed time: 96332 seconds
Comment 1 Mike Jakubik 2011-09-16 18:50:26 UTC
This appears to be a problem with the new jpeg encoder code in OpenJDKs javax.imageio. We have changed our code to render a PNG instead, and the issue appears to be solved.
Comment 2 Christopher Schultz 2011-09-16 20:51:10 UTC
There was a recent discussion on the users list where someone discovered that one of the JRE imaging APIs was keeping a reference to an OutputStream and randonly flushing it long after the request had completed.

http://markmail.org/thread/pg6tcml5rvuiifv2

This wasn't causing crashes, though.

I wonder if this might be a related problem: the output stream is flushed, but the response has already been sent and the thread/buffer put back into the worker queue. When another flush comes, it's in an invalid state?

Mike, would you be willing to try to reproduce the problem and then wrap an OutputStream around the response's OutputStream, and pass THAT to the ImageIO?

See here for an example of the kind of code I'm talking about:
https://wiki.apache.org/tomcat/FAQ/KnownIssues#ImageIOIssues
Comment 3 Mike Jakubik 2011-09-20 16:08:58 UTC
Hi Christopher,

Thanks for the info, but it appears that simply switching to render a png instead of a jpeg has fixed our problem. Unfortunately i am not a programmer myself, and i don't have the resources to try your code.

Thanks.
Comment 4 Christopher Schultz 2013-05-21 20:12:06 UTC
We have another bite:
http://markmail.org/message/f5idaje4a4vg7vkd

Updated versions of everything, but the symptom is the same: ImageIO bug + APR + sendbb() + si_addr=0x0000000000000040
Comment 5 Christopher Schultz 2013-05-21 20:12:39 UTC
I think this ought to do it (though I'm sure there are other places in tcnative that could afford to have this same kind of checking):


Index: native/src/network.c
===================================================================
--- native/src/network.c	(revision 1484904)
+++ native/src/network.c	(working copy)
@@ -587,6 +587,10 @@
         tcn_ThrowAPRException(e, APR_ENOTSOCK);
         return -(jint)APR_ENOTSOCK;
     }
+    if(!s->net) {
+      tcn_ThrowAPRException(e, APR_EINVALSOCK);
+      return -(jint)APR_EINVALSOCK;
+    }
     TCN_ASSERT(s->opaque != NULL);
     TCN_ASSERT(s->jsbbuff != NULL);
 #ifdef TCN_DO_STATISTICS
Comment 6 Christopher Schultz 2013-05-21 20:13:09 UTC
(Note the above example patch is against tcnative/1.1.x branch)
Comment 7 Christopher Schultz 2013-06-06 16:20:28 UTC
Created attachment 30402 [details]
Patch against tcnative-1.1.x

I'm not sure if I should be checking s->net or s->sock. They both seem to be set to NULL in the various recycle routines so it probably doesn't matter either way.

I'm also not sure if APR_EINVALSOCK is the right error code to use.
Comment 8 Rainer Jung 2013-06-07 16:18:31 UTC
(In reply to Christopher Schultz from comment #7)
> Created attachment 30402 [details]
> Patch against tcnative-1.1.x
> 
> I'm not sure if I should be checking s->net or s->sock. They both seem to be
> set to NULL in the various recycle routines so it probably doesn't matter
> either way.

I'd go with the net member and add the check to and function of name send* and recv*, which already have the null pointer check for s (or its jlong equivalent sock).

> I'm also not sure if APR_EINVALSOCK is the right error code to use.

 * APR_EINVALSOCK   APR was given an invalid socket
 * APR_ENOSOCKET    APR was not given a socket

So APR_EINVALSOCK sounds good.

I haven't though checked the code that calls the recv* and send* methods for special error handling.

Regards,

Rainer
Comment 9 Christopher Schultz 2013-06-07 19:59:49 UTC
(In reply to Rainer Jung from comment #8)
> (In reply to Christopher Schultz from comment #7)
> > Created attachment 30402 [details]
> > Patch against tcnative-1.1.x
> > 
> > I'm not sure if I should be checking s->net or s->sock. They both seem to be
> > set to NULL in the various recycle routines so it probably doesn't matter
> > either way.
> 
> I'd go with the net member and add the check to and function of name send*
> and recv*, which already have the null pointer check for s (or its jlong
> equivalent sock).

I think that's pretty much what I've done. Do you think I missed anything?

> > I'm also not sure if APR_EINVALSOCK is the right error code to use.
> 
>  * APR_EINVALSOCK   APR was given an invalid socket
>  * APR_ENOSOCKET    APR was not given a socket
> 
> So APR_EINVALSOCK sounds good.

Okay, I'll commit as-is, then.
Comment 10 Rainer Jung 2013-08-05 08:29:14 UTC
Here's another occurance:

    [junit] Running org.apache.tomcat.websocket.TestWebSocketFrameClient
    [junit] Aug 02, 2013 2:52:50 PM org.apache.catalina.core.AprLifecycleListener init
    [junit] INFO: Loaded APR based Apache Tomcat Native library 1.1.27 using APR version 1.4.8.
    [junit] Aug 02, 2013 2:52:50 PM org.apache.catalina.core.AprLifecycleListener init
    [junit] INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
    [junit] Aug 02, 2013 2:52:50 PM org.apache.catalina.core.AprLifecycleListener initializeSSL
    [junit] INFO: OpenSSL successfully initialized (OpenSSL 1.0.1esp1 12 Feb 2013)
    [junit] Aug 02, 2013 2:52:52 PM org.apache.coyote.AbstractProtocol init
    [junit] INFO: Initializing ProtocolHandler ["http-apr-127.0.0.1-auto-1"]
    [junit] Aug 02, 2013 2:52:52 PM org.apache.catalina.core.StandardService startInternal
    [junit] INFO: Starting service Tomcat
    [junit] Aug 02, 2013 2:52:52 PM org.apache.catalina.core.StandardEngine startInternal
    [junit] INFO: Starting Servlet Engine: Apache Tomcat/8.0.0-RC1
    [junit] Aug 02, 2013 2:52:53 PM org.apache.coyote.AbstractProtocol start
    [junit] INFO: Starting ProtocolHandler ["http-apr-127.0.0.1-auto-1-59353"]
    [junit] Aug 02, 2013 2:53:53 PM org.apache.coyote.AbstractProtocol pause
    [junit] INFO: Pausing ProtocolHandler ["http-apr-127.0.0.1-auto-1-59353"]
    [junit] Aug 02, 2013 2:53:54 PM org.apache.catalina.core.StandardService stopInternal
    [junit] INFO: Stopping service Tomcat
    [junit] Aug 02, 2013 2:53:54 PM org.apache.coyote.AbstractProtocol stop
    [junit] INFO: Stopping ProtocolHandler ["http-apr-127.0.0.1-auto-1-59353"]
    [junit] #
    [junit] # A fatal error has been detected by the Java Runtime Environment:
    [junit] #
    [junit] #  SIGSEGV (0xb) at pc=0xb76dfe74, pid=11403, tid=26
    [junit] #
    [junit] # JRE version: 7.0_25-b15
    [junit] # Java VM: Java HotSpot(TM) Server VM (23.25-b01 mixed mode solaris-sparc )
    [junit] # Problematic frame:
    [junit] # C  [libtcnative-1.so.0.1.27+0xfe74]Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 66.655 sec
    [junit]   Java_org_apache_tomcat_jni_Socket_recv+0x34
    [junit] #
    [junit] # Core dump written. Default location: /shared/build/dev/tomcat/incoming/tc8.0.x/8.0.0-RC1/tmp-8.0.0-RC1/apache-tomcat-8.0.0-RC1-src-gz/core or core.11403
    [junit] #
    [junit] # An error report file with more information is saved as:
    [junit] # /shared/build/dev/tomcat/incoming/tc8.0.x/8.0.0-RC1/tmp-8.0.0-RC1/apache-tomcat-8.0.0-RC1-src-gz/hs_err_pid11403.log
    [junit]                  -------------
    [junit]   0  (0xb7af8558)  [b6|00|   24]
    [junit]                  [   0x00000000]
    [junit]                  [   0xb794be80]
    [junit]                  [   0x0c800001]
    [junit]                  -------------
    [junit]   1  (0xb7af8568)  [00|b7|   25]
    [junit]                  [   0xb7af6f78]
    [junit]                  [   0x00000000]
    [junit]                  [   0x80800001]
    [junit]                  -------------



 b76dfe74 Java_org_apache_tomcat_jni_Socket_recv (30b528, b30ff188,
b30fd09c, b29500, b30ff214, 0) + 34
 fbc0f780 * org/apache/tomcat/jni/Socket.recv(J[BII)I+32362
 fbc0f72c * org/apache/tomcat/jni/Socket.recv(J[BII)I+0
 fbc068ec *
org/apache/coyote/http11/upgrade/AprServletInputStream.doRead(Z[BII)I+73
(line 101)
 fbc068ec *
org/apache/coyote/http11/upgrade/AbstractServletInputStream.read([BII)I+20
(line 229)
 fbc068ec *
org/apache/tomcat/websocket/server/WsFrameServer.onDataAvailable()V+46
(line 89)
 fbc06b84 *
org/apache/tomcat/websocket/server/WsHttpUpgradeHandler$WsReadListener.onDataAvailable()V+4
(line 384)
 fbc0771c *
org/apache/coyote/http11/upgrade/AbstractServletInputStream.onDataAvailable()V+11
(line 337)
 fbc06b84 *
org/apache/coyote/http11/upgrade/AbstractProcessor.upgradeDispatch(Lorg/apache/tomcat/util/net/SocketStatus;)Lorg/apache/tomcat/util/net/AbstractEndpoint$Handler$SocketState;+11
(line 189)
 fbc073e0 *
org/apache/coyote/AbstractProtocol$AbstractConnectionHandler.process(Lorg/apache/tomcat/util/net/SocketWrapper;Lorg/apache/tomcat/util/net/SocketStatus;)Lorg/apache/tomcat/util/net/AbstractEndpoint$Handler$SocketState;+171
(line 1221)
 fbc06848 *
org/apache/coyote/http11/Http11AprProtocol$Http11ConnectionHandler.process(Lorg/apache/tomcat/util/net/SocketWrapper;Lorg/apache/tomcat/util/net/SocketStatus;)Lorg/apache/tomcat/util/net/AbstractEndpoint$Handler$SocketState;+76
(line 546)
 fbc073e0 *
org/apache/tomcat/util/net/AprEndpoint$SocketProcessor.doRun()V+26 (line
4492)
 fbc06b84 *
org/apache/tomcat/util/net/AprEndpoint$SocketProcessor.run()V+55 (line 4468)
...

GDB tells my:

#7  0xb76dfe74 in Java_org_apache_tomcat_jni_Socket_recv (e=0x30b528,
o=0xb30ff188, sock=<optimized out>, buf=0xb30ff214, offset=0,
toread=8192) at src/network.c:733
733             if ((ss = (*s->net->recv)(s->opaque, sb, &nbytes)) ==
APR_SUCCESS)

#7  0xb76dfe74 in Java_org_apache_tomcat_jni_Socket_recv (e=0x30b528,
o=0xb30ff188, sock=<optimized out>, buf=0xb30ff214, offset=0,
toread=8192) at src/network.c:733
        sb =
"\000\006\026\200\000\fÞ̳\017Ñ\000·\205{Í·\205{س\017Ñ\234³\017Ñ\030³\017Ш·\227(p»\204H\200ò\032\226x\000\000\000\023\000\000\000\000ûÁ\227hò\032\227\020³\017Ñ8³\017Ñ8ûÀhH\000\000\b¹³\017Ñh³\017ÑHûÀhH³\017ÑP\000\000\002°·\211+Ø\000\000\000u\000\000\000\000ò\032\227
ò\032\226\210ò\032\226\210\000\000\000u\000\000\000\000³\017ÑhûÀhH»\204Hh¼Ð¬h\000\000\001\032\000\000\000\000³\017Ñ\230·\225x'·\225xH³\017Ò$³\017Ñ ³\017Ñ8·\225}ø\000\060´\000\000\000\000\000\000\000\000¶\000\000\000\000ûÁÄÀ"...
        s = 0xb29500
        nbytes = 8192
        ss = <optimized out>

(gdb) print *s
$5 = {pool = 0xb294c0, child = 0x0, sock = 0x0, opaque = 0xb297d8,
  jsbbuff = 0x330398 "HTTP/1.1 101 Switching Protocols\r\nServer:
Apache-Coyote/1.1\r\nUpgrade: websocket\r\nConnection:
upgrade\r\nSec-WebSocket-Accept: tPEj68f24a5073zco+NHsEUCKpY=\r\nDate:
Fri, 02 Aug 2013 12:52:53 GMT\r\n\r\n",
  jrbbuff = 0xbfbc78 "GET /firehose HTTP/1.1\r\nSec-WebSocket-Version:
13\r\nUpgrade: websocket\r\nHost: localhost:59353\r\nSec-WebSocket-Key:
qzlX6/aQxs4TAKyKCb+XLg==\r\nConnection: upgrade\r\n\r\n", net = 0x0, pe
= 0xb87958, last_active = 0, timeout = -2}

The reason for the crash is likely:

(gdb) print s->net
$7 = (tcn_nlayer_t *) 0x0

So dereferencing it in (*s->net->recv) gives a segfault.
Comment 11 Christopher Schultz 2013-08-28 14:53:31 UTC
Fixed in 1.1.x in r1518225, will be available in tcnative-1.1.28.

Note that I did not add further checking for s->net->send and/or s->net->recv. Please re-open if it appears that will be necessary.