Hi Stefan, live. Sorry for the late reply.
Stefan Am 28.02.2017 um 11:49 schrieb Stefan Eissing: > Meh, my mistake. Sorry about that. Did not cleanup properly. Dare you with an > improved version: > > > > > >> Am 28.02.2017 um 08:41 schrieb Stefan Priebe - Profihost AG >> <s.pri...@profihost.ag>: >> >> That one breaks everyting. Multiple crashes per second. >> >> [Thread debugging using libthread_db enabled] >> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". >> Core was generated by `/usr/local/apache/bin/httpd -DFOREGROUND'. >> Program terminated with signal SIGABRT, Aborted. >> #0 0x00007f02724ea067 in raise () from /lib/x86_64-linux-gnu/libc.so.6 >> #0 0x00007f02724ea067 in raise () from /lib/x86_64-linux-gnu/libc.so.6 >> #1 0x00007f02724eb448 in abort () from /lib/x86_64-linux-gnu/libc.so.6 >> #2 0x00007f02724e3266 in ?? () from /lib/x86_64-linux-gnu/libc.so.6 >> #3 0x00007f02724e3312 in __assert_fail () from >> /lib/x86_64-linux-gnu/libc.so.6 >> #4 0x00007f027287062f in __pthread_tpp_change_priority () >> from /lib/x86_64-linux-gnu/libpthread.so.0 >> #5 0x00007f0272865e9f in __pthread_mutex_lock_full () >> from /lib/x86_64-linux-gnu/libpthread.so.0 >> #6 0x00007f0272a98db8 in allocator_alloc (in_size=in_size@entry=8032, >> allocator=0x7f025c03f3c0) at memory/unix/apr_pools.c:244 >> #7 apr_allocator_alloc (allocator=0x7f025c03f3c0, size=size@entry=8032) >> at memory/unix/apr_pools.c:438 >> #8 0x00007f0272cbcac4 in apr_bucket_alloc (size=8032, size@entry=8000, >> list=0x7f022c0008e8) at buckets/apr_buckets_alloc.c:157 >> #9 0x00007f0272cbdca2 in socket_bucket_read (a=0x7f022c000b08, >> str=0x7f02627a87b8, len=0x7f02627a87c0, block=<optimized out>) >> at buckets/apr_buckets_socket.c:34 >> #10 0x0000565098cf1fb1 in ap_core_input_filter (f=0x7f022c0056b0, >> b=0x7f022c005630, mode=<optimized out>, block=APR_NONBLOCK_READ, >> readbytes=5) at core_filters.c:235 >> #11 0x0000565098d3aaca in logio_in_filter (f=<optimized out>, >> bb=0x7f022c005630, mode=<optimized out>, block=<optimized out>, >> readbytes=<optimized out>) at mod_logio.c:165 >> #12 0x0000565098d45b9a in bio_filter_in_read (bio=0x7f024800b460, >> in=0x7f02480492a3 "", inlen=5) at ssl_engine_io.c:483 >> #13 0x00007f02736b014c in BIO_read () >> from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0 >> #14 0x00007f0273a13c92 in ?? () from >> /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 >> #15 0x00007f0273a1548d in ?? () from >> /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 >> #16 0x00007f0273a12024 in ?? () from >> /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 >> #17 0x0000565098d469f3 in ssl_io_input_read (inctx=0x7f022c0035b8, >> buf=0x7f022c003600 "GET >> /media/image/07/3c/c2/4612_13721_160192280322.jpeg HTTP/1.1\r\nHost: >> www.onlinestore.it\r\nUser-Agent: curl/7.15+ (x64-criteo) libcurl/7.15+ >> OpenSSL zlib libidn\r\nAccept: */*\r\n\r\n", len=0x7f02627a8b38) >> at ssl_engine_io.c:614 >> #18 0x0000565098d493ec in ssl_io_filter_input (f=0x7f022c005608, >> bb=0x7f022c006dd0, mode=<optimized out>, block=<optimized out>, >> readbytes=8000) at ssl_engine_io.c:1474 >> #19 0x0000565098d5cd85 in h2_filter_core_input (f=0x7f022c005980, >> brigade=0x7f022c006dd0, mode=738225624, block=APR_NONBLOCK_READ, >> readbytes=8000) at h2_filter.c:149 >> #20 0x0000565098d6809b in h2_session_read (session=0x7f022c006920, >> block=<optimized out>) at h2_session.c:1440 >> #21 0x0000565098d6b97f in h2_session_process (session=0x7f022c006920, >> async=3964) at h2_session.c:2074 >> #22 0x0000565098d5b84e in h2_conn_run (ctx=<optimized out>, >> c=0x7f025c03f7d8) >> at h2_conn.c:218 >> #23 0x0000565098d5e551 in h2_h2_process_conn (c=0x7f025c03f7d8) at >> h2_h2.c:658 >> #24 0x0000565098d00fd0 in ap_run_process_connection (c=0x7f025c03f7d8) >> at connection.c:42 >> #25 0x0000565098d9b6d0 in process_socket (my_thread_num=<optimized out>, >> my_child_num=<optimized out>, cs=0x7f025c03f748, sock=<optimized out>, >> p=<optimized out>, thd=<optimized out>) at event.c:1134 >> #26 worker_thread (thd=0xf5e, dummy=0xf7c) at event.c:2137 >> #27 0x00007f02728680a4 in start_thread () >> from /lib/x86_64-linux-gnu/libpthread.so.0 >> #28 0x00007f027259d62d in clone () from /lib/x86_64-linux-gnu/libc.so.6 >> (gdb) (gdb) quit >> Reading symbols from /usr/local/apache/bin/httpd...Reading symbols from >> /usr/lib/debug//usr/local/apache2/bin/httpd...done. >> done. >> [Thread debugging using libthread_db enabled] >> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". >> Core was generated by `/usr/local/apache/bin/httpd -DFOREGROUND'. >> Program terminated with signal SIGABRT, Aborted. >> #0 0x00007f02724ea067 in raise () from /lib/x86_64-linux-gnu/libc.so.6 >> #0 0x00007f02724ea067 in raise () from /lib/x86_64-linux-gnu/libc.so.6 >> #1 0x00007f02724eb448 in abort () from /lib/x86_64-linux-gnu/libc.so.6 >> #2 0x00007f02724e3266 in ?? () from /lib/x86_64-linux-gnu/libc.so.6 >> #3 0x00007f02724e3312 in __assert_fail () from >> /lib/x86_64-linux-gnu/libc.so.6 >> #4 0x00007f027287062f in __pthread_tpp_change_priority () >> from /lib/x86_64-linux-gnu/libpthread.so.0 >> #5 0x00007f0272865e9f in __pthread_mutex_lock_full () >> from /lib/x86_64-linux-gnu/libpthread.so.0 >> #6 0x00007f0272a98db8 in allocator_alloc (in_size=in_size@entry=8032, >> allocator=0x7f025c03d320) at memory/unix/apr_pools.c:244 >> #7 apr_allocator_alloc (allocator=0x7f025c03d320, size=size@entry=8032) >> at memory/unix/apr_pools.c:438 >> #8 0x00007f0272cbcac4 in apr_bucket_alloc (size=8032, size@entry=8000, >> list=0x7f02340008e8) at buckets/apr_buckets_alloc.c:157 >> #9 0x00007f0272cbdca2 in socket_bucket_read (a=0x7f0234000b08, >> str=0x7f0260fa57b8, len=0x7f0260fa57c0, block=<optimized out>) >> at buckets/apr_buckets_socket.c:34 >> #10 0x0000565098cf1fb1 in ap_core_input_filter (f=0x7f02340056b0, >> b=0x7f0234005630, mode=<optimized out>, block=APR_NONBLOCK_READ, >> readbytes=5) at core_filters.c:235 >> #11 0x0000565098d3aaca in logio_in_filter (f=<optimized out>, >> bb=0x7f0234005630, mode=<optimized out>, block=<optimized out>, >> readbytes=<optimized out>) at mod_logio.c:165 >> #12 0x0000565098d45b9a in bio_filter_in_read (bio=0x7f022801ff50, >> in=0x7f02280345d3 "(\002\177", inlen=5) at ssl_engine_io.c:483 >> #13 0x00007f02736b014c in BIO_read () >> from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0 >> #14 0x00007f0273a13c92 in ?? () from >> /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 >> #15 0x00007f0273a1548d in ?? () from >> /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 >> #16 0x00007f0273a12024 in ?? () from >> /usr/lib/x86_64-linux-gnu/libssl.so.1.0.0 >> #17 0x0000565098d469f3 in ssl_io_input_read (inctx=0x7f02340035b8, >> buf=0x7f0234003600 "", len=0x7f0260fa5b38) at ssl_engine_io.c:614 >> #18 0x0000565098d493ec in ssl_io_filter_input (f=0x7f0234005608, >> bb=0x7f023400cd00, mode=<optimized out>, block=<optimized out>, >> readbytes=8000) at ssl_engine_io.c:1474 >> #19 0x0000565098d5cd85 in h2_filter_core_input (f=0x7f0234005980, >> brigade=0x7f023400cd00, mode=872467720, block=APR_NONBLOCK_READ, >> readbytes=8000) at h2_filter.c:149 >> #20 0x0000565098d6809b in h2_session_read (session=0x7f023400c850, >> block=<optimized out>) at h2_session.c:1440 >> #21 0x0000565098d6b97f in h2_session_process (session=0x7f023400c850, >> async=4029) at h2_session.c:2074 >> #22 0x0000565098d5b84e in h2_conn_run (ctx=<optimized out>, >> c=0x7f025c03d738) >> at h2_conn.c:218 >> #23 0x0000565098d5e551 in h2_h2_process_conn (c=0x7f025c03d738) at >> h2_h2.c:658 >> #24 0x0000565098d00fd0 in ap_run_process_connection (c=0x7f025c03d738) >> at connection.c:42 >> #25 0x0000565098d9b6d0 in process_socket (my_thread_num=<optimized out>, >> my_child_num=<optimized out>, cs=0x7f025c03d6a8, sock=<optimized out>, >> p=<optimized out>, thd=<optimized out>) at event.c:1134 >> #26 worker_thread (thd=0xf9c, dummy=0xfbd) at event.c:2137 >> #27 0x00007f02728680a4 in start_thread () >> from /lib/x86_64-linux-gnu/libpthread.so.0 >> #28 0x00007f027259d62d in clone () from /lib/x86_64-linux-gnu/libc.so.6 >> >> Stefan >> >> Am 27.02.2017 um 19:44 schrieb Stefan Eissing: >>> Damnit. Can you try the attached patch on top of mod_http2 v1.9.2? This one >>> sets a mutex on the main connection allocator if missing and is pretty >>> close to the version we ran successfully with on your site for days. >>> >>> Thanks again! >>> >>> -Stefan >>> >>> >>> >>> >>>> Am 27.02.2017 um 16:22 schrieb Stefan Priebe - Profihost AG >>>> <s.pri...@profihost.ag>: >>>> >>>> Hi Stefan, >>>> >>>> two new crashes here. >>>> >>>> Reading symbols from /usr/local/apache/bin/httpd...Reading symbols from >>>> /usr/lib/debug//usr/local/apache2/bin/httpd...done. >>>> done. >>>> (gdb) (gdb) quit >>>> Reading symbols from /usr/local/apache/bin/httpd...Reading symbols from >>>> /usr/lib/debug//usr/local/apache2/bin/httpd...done. >>>> done. >>>> [Thread debugging using libthread_db enabled] >>>> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". >>>> Core was generated by `/usr/local/apache/bin/httpd -DFOREGROUND'. >>>> Program terminated with signal SIGSEGV, Segmentation fault. >>>> #0 allocator_free (node=0x0, allocator=0x7f458005a320) >>>> at memory/unix/apr_pools.c:381 >>>> #0 allocator_free (node=0x0, allocator=0x7f458005a320) >>>> at memory/unix/apr_pools.c:381 >>>> #1 apr_pool_clear (pool=0x7f458004bec8) at memory/unix/apr_pools.c:793 >>>> #2 0x0000560ce83e5718 in ap_push_pool (queue_info=0x0, >>>> pool_to_recycle=0x7f458005a328) at fdqueue.c:234 >>>> #3 0x0000560ce83e0a5a in process_lingering_close (cs=0x7f458004c158, >>>> pfd=0x560ce8b8dda8) at event.c:1513 >>>> #4 0x0000560ce83e4590 in listener_thread (thd=0x0, dummy=0x5497f5242585c) >>>> at event.c:1837 >>>> #5 0x00007f45967610a4 in start_thread () >>>> from /lib/x86_64-linux-gnu/libpthread.so.0 >>>> #6 0x00007f459649662d in clone () from /lib/x86_64-linux-gnu/libc.so.6 >>>> (gdb) (gdb) quit >>>> >>>> >>>> Reading symbols from /usr/local/apache/bin/httpd...Reading symbols from >>>> /usr/lib/debug//usr/local/apache2/bin/httpd...done. >>>> done. >>>> [Thread debugging using libthread_db enabled] >>>> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". >>>> Core was generated by `/usr/local/apache/bin/httpd -DFOREGROUND'. >>>> Program terminated with signal SIGSEGV, Segmentation fault. >>>> #0 allocator_free (node=0x0, allocator=0x7f4580062840) >>>> at memory/unix/apr_pools.c:381 >>>> #0 allocator_free (node=0x0, allocator=0x7f4580062840) >>>> at memory/unix/apr_pools.c:381 >>>> #1 apr_pool_clear (pool=0x7f4580069188) at memory/unix/apr_pools.c:793 >>>> #2 0x0000560ce83e5718 in ap_push_pool (queue_info=0x0, >>>> pool_to_recycle=0x7f4580062848) at fdqueue.c:234 >>>> #3 0x0000560ce83e0a5a in process_lingering_close (cs=0x7f4580069418, >>>> pfd=0x560ce8b8dda8) at event.c:1513 >>>> #4 0x0000560ce83e4590 in listener_thread (thd=0x0, dummy=0x549845279ce62) >>>> at event.c:1837 >>>> #5 0x00007f45967610a4 in start_thread () >>>> from /lib/x86_64-linux-gnu/libpthread.so.0 >>>> #6 0x00007f459649662d in clone () from /lib/x86_64-linux-gnu/libc.so.6 >>>> (gdb) (gdb) quit >>>> >>>> Stefan >>>> Am 26.02.2017 um 19:46 schrieb Stefan Priebe - Profihost AG: >>>>> Hi Stefan, >>>>> >>>>> currently everything fine. No segfaults. >>>>> >>>>> Stefan >>>>> >>>>> Am 25.02.2017 um 20:40 schrieb Stefan Priebe - Profihost AG: >>>>>> Hi Stefan, >>>>>> Am 25.02.2017 um 13:51 schrieb Stefan Eissing: >>>>>>> Stefan, >>>>>>> >>>>>>> whenever you have time, please deploy >>>>>>> https://github.com/icing/mod_h2/releases/tag/v1.9.2 >>>>>>> >>>>>>> I added an own allocator with mutex to the http/2 main session. That is >>>>>>> something of a middle-ground between placing that on the main conn (as >>>>>>> we had in the crash free version) and 1.9.1 behaviour. Thanks! >>>>>> >>>>>> done. But please keep in mind that this crash might be very rare and >>>>>> might even have happened with v1.9.0 if we've waited more time. >>>>>> >>>>>> Greets, >>>>>> Stefan >>>>>> >>>>>>> -Stefan >>>>>>> >>>>>>>> Am 24.02.2017 um 19:31 schrieb Stefan Priebe - Profihost AG >>>>>>>> <s.pri...@profihost.ag>: >>>>>>>> >>>>>>>> Hi Yann, >>>>>>>> >>>>>>>> here we go: >>>>>>>> >>>>>>>> (gdb) p *ipsub >>>>>>>> $1 = {family = 2, sub = {1367753145, 0, 0, 0}, mask = {4294967295, >>>>>>>> 4294967295, 4294967295, 4294967295}} >>>>>>>> >>>>>>>> (gdb) p *sa >>>>>>>> $2 = {pool = 0x10b500c4ff0b0a, hostname = 0x503040203030102 <error: >>>>>>>> Cannot access memory at address 0x503040203030102>, >>>>>>>> servname = 0x17d010000040405 <error: Cannot access memory at address >>>>>>>> 0x17d010000040405>, port = 770, family = 554829073, >>>>>>>> salen = 319177009, ipaddr_len = 570909009, addr_str_len = -2127424399, >>>>>>>> ipaddr_ptr = 0x24f0d15215c1b142, >>>>>>>> next = 0x17160a0982726233, sa = {sin = {sin_family = 6424, sin_port = >>>>>>>> 9498, sin_addr = {s_addr = 690497318}, >>>>>>>> sin_zero = "*456789:"}, sin6 = {sin6_family = 6424, sin6_port = >>>>>>>> 9498, sin6_flowinfo = 690497318, sin6_addr = {__in6_u = { >>>>>>>> __u6_addr8 = "*456789:CDEFGHIJ", __u6_addr16 = {13354, 13877, >>>>>>>> 14391, 14905, 17475, 17989, 18503, 19017}, __u6_addr32 = { >>>>>>>> 909456426, 976828471, 1178944579, 1246316615}}}, >>>>>>>> sin6_scope_id = 1448432723}, sas = {ss_family = 6424, >>>>>>>> __ss_align = 4195446337656140842, >>>>>>>> __ss_padding = >>>>>>>> "CDEFGHIJSTUVWXYZcdefghijstuvwxyz\203\204\205\206\207\210\211\212\222\223\224\225\226\227\230\231\232\242\243\244\245\246\247\250\251\252\262\263\264\265\266\267\270\271\272\302\303\304\305\306\307\310\311\312\322\323\324\325\326\327\330\331\332\341\342\343\344\345\346\347\350\351\352\361\362\363\364\365\366\367\370\371\372\377\304\000\037\001\000\003"}}} >>>>>>>> >>>>>>>> (gdb) p *(struct in6_addr *)sa >>>>>>>> $3 = {__in6_u = {__u6_addr8 = >>>>>>>> "\n\v\377\304\000\265\020\000\002\001\003\003\002\004\003\005", >>>>>>>> __u6_addr16 = {2826, 50431, 46336, >>>>>>>> 16, 258, 771, 1026, 1283}, __u6_addr32 = {3305048842, 1094912, >>>>>>>> 50528514, 84083714}}} >>>>>>>> >>>>>>>> >>>>>>>> Stefan >>>>>>>> >>>>>>>> Am 24.02.2017 um 14:18 schrieb Yann Ylavic: >>>>>>>>> Hi Stefan (Priebe), >>>>>>>>> >>>>>>>>> Is IPv6 (really) involved in your network? >>>>>>>>> >>>>>>>>> Could you please show up the gdb output of the below ? >>>>>>>>> >>>>>>>>> On Fri, Feb 24, 2017 at 2:07 PM, Yann Ylavic <ylavic....@gmail.com> >>>>>>>>> wrote: >>>>>>>>>> >>>>>>>>>> 1078 APR_DECLARE(int) apr_ipsubnet_test(apr_ipsubnet_t *ipsub, >>>>>>>>>> apr_sockaddr_t *sa) >>>>>>>>>> 1079 { >>>>>>>>>> 1080 #if APR_HAVE_IPV6 >>>>>>>>>> 1081 /* XXX This line will segv on Win32 build with >>>>>>>>>> APR_HAVE_IPV6, >>>>>>>>>> 1082 * but without the IPV6 drivers installed. >>>>>>>>>> 1083 */ >>>>>>>>>> 1084 if (sa->family == AF_INET) { >>>>>>>>>> 1085 if (ipsub->family == AF_INET && >>>>>>>>>> 1086 ((sa->sa.sin.sin_addr.s_addr & ipsub->mask[0]) == >>>>>>>>>> ipsub->sub[0])) { >>>>>>>>>> 1087 return 1; >>>>>>>>>> 1088 } >>>>>>>>>> 1089 } >>>>>>>>>> 1090 else if (IN6_IS_ADDR_V4MAPPED((struct in6_addr >>>>>>>>>> *)sa->ipaddr_ptr)) { >>>>>>>>>> 1091 if (ipsub->family == AF_INET && >>>>>>>>>> 1092 (((apr_uint32_t *)sa->ipaddr_ptr)[3] & >>>>>>>>>> ipsub->mask[0]) == ipsub->sub[0]) { >>>>>>>>>> 1093 return 1; >>>>>>>>>> 1094 } >>>>>>>>>> 1095 } >>>>>>>>> >>>>>>>>> (gdb) p *ipsub >>>>>>>>> (gdb) p *sa >>>>>>>>> (gdb) p *(struct in6_addr *)sa >>>>>>>>> >>>>>>>>> and possibly more to come... >>>>>>>>> >>>>>>>>> >>>>>>>>> Thanks, >>>>>>>>> Yann. >>>>>>>>> >>>>>>> >>>>>>> Stefan Eissing >>>>>>> >>>>>>> <green/>bytes GmbH >>>>>>> Hafenstrasse 16 >>>>>>> 48155 Münster >>>>>>> www.greenbytes.de >>>>>>> >>> >>> Stefan Eissing >>> >>> <green/>bytes GmbH >>> Hafenstrasse 16 >>> 48155 Münster >>> www.greenbytes.de >>> > > Stefan Eissing > > <green/>bytes GmbH > Hafenstrasse 16 > 48155 Münster > www.greenbytes.de >