Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Crystal::ThreadLocalValue(Deque(Fiber)), Thread... Server hangs, crash, Deadlock? #8714

Closed
636f7374 opened this issue Jan 24, 2020 · 11 comments

Comments

@636f7374
Copy link

636f7374 commented Jan 24, 2020

Summary

Server sometimes gets stuck and crash.
I captured the call stack, is it related Crystal::ThreadLocalValue (Deque (Fiber))?
And two related crashes that were triggered earlier.
In addition lsof (UNIXSocket) will appear (none).
This problem only happens occasionally.
The server encounters this problem and will slowly process the client, and a hang issue occurs.
Sorry, i can't provide more information, if it can't be solved, just make a note.

Call graph (with -Dpreview_mt)

  • Problem
Call graph:
    27014 Thread_288550   DispatchQueue_1: com.apple.main-thread  (serial)
    + 27014 ~procProc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47  (in toucan) + 9  [0x109a53509]
    +   27014 *Fiber#run:(IO::FileDescriptor | Nil)  (in toucan) + 83  [0x109ac89a3]
    +     27014 ~procProc(Nil)@/usr/local/Cellar/crystal/0.32.1/src/kernel.cr:542  (in toucan) + 24  [0x109a533e8]
    +       27014 *sleep<Int32>:Nil  (in toucan) + 66  [0x109a53442]
    +         27014 *Crystal::Scheduler::sleep<Time::Span>:Nil  (in toucan) + 57  [0x109ae4469]
    +           27014 *Crystal::Scheduler#sleep<Time::Span>:Nil  (in toucan) + 84  [0x109ae44c4]
    +             27014 *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x109ae3c53]
    +               27014 *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x109ae249a]  event_loop_libevent.cr:18
    +                 27014 *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x109ae3171]  event_libevent.cr:62
    +                   27014 event_base_loop  (in libevent-2.1.7.dylib) + 1074  [0x10a5f64ba]
    +                     27014 event_process_active_single_queue  (in libevent-2.1.7.dylib) + 383  [0x10a5f8fe7]
    +                       27014 ~proc4Proc(Int32, LibEvent2::EventFlags, Pointer(Void), Nil)@/usr/local/Cellar/crystal/0.32.1/src/crystal/system/unix/event_loop_libevent.cr:52  (in toucan) + 101  [0x109a575a5]
    +                         27014 *Socket+@IO::Evented#resume_read<Bool>:Nil  (in toucan) + 46  [0x109b883de]
    +                           27014 *Crystal::ThreadLocalValue(Deque(Fiber))@Crystal::ThreadLocalValue(T)#get?:(Deque(Fiber) | Nil)  (in toucan) + 28  [0x109adbcfc]
    +                             24995 *Crystal::SpinLock#lock:Nil  (in toucan) + 78  [0x109adde7e]
    +                             ! 24995 *Intrinsics::pause:Nil  (in toucan) + 6,7,...  [0x109ae0756,0x109ae0757,...]  intrinsics.cr:62
    +                             1169 *Crystal::SpinLock#lock:Nil  (in toucan) + 54,73,...  [0x109adde66,0x109adde79,...]
    +                             850 *Crystal::SpinLock#lock:Nil  (in toucan) + 68  [0x109adde74]
    +                               850 *Atomic(Int32)@Atomic(T)#get:Int32  (in toucan) + 6,1,...  [0x109ac8256,0x109ac8251,...]  atomic.cr:191
    27014 Thread_288551
    + 27014 thread_start  (in libsystem_pthread.dylib) + 13  [0x7fff994ae08d]
    +   27014 _pthread_start  (in libsystem_pthread.dylib) + 286  [0x7fff994ae887]
    +     27014 _pthread_body  (in libsystem_pthread.dylib) + 180  [0x7fff994ae93b]
    +       27014 GC_mark_thread  (in toucan) + 132  [0x109d24458]
    +         27014 GC_help_marker  (in toucan) + 46  [0x109d1e7a6]
    +           27014 GC_wait_marker  (in toucan) + 23  [0x109d25c85]
    +             27014 _pthread_cond_wait  (in libsystem_pthread.dylib) + 712  [0x7fff994af7fa]
    +               27014 __psynch_cvwait  (in libsystem_kernel.dylib) + 10  [0x7fff993c3bf2]
    27014 Thread_288552
    + 27014 thread_start  (in libsystem_pthread.dylib) + 13  [0x7fff994ae08d]
    +   27014 _pthread_start  (in libsystem_pthread.dylib) + 286  [0x7fff994ae887]
    +     27014 _pthread_body  (in libsystem_pthread.dylib) + 180  [0x7fff994ae93b]
    +       27014 GC_mark_thread  (in toucan) + 132  [0x109d24458]
    +         27014 GC_help_marker  (in toucan) + 46  [0x109d1e7a6]
    +           27014 GC_wait_marker  (in toucan) + 23  [0x109d25c85]
    +             27014 _pthread_cond_wait  (in libsystem_pthread.dylib) + 712  [0x7fff994af7fa]
    +               27014 __psynch_cvwait  (in libsystem_kernel.dylib) + 10  [0x7fff993c3bf2]
    27014 Thread_288553
    + 27014 thread_start  (in libsystem_pthread.dylib) + 13  [0x7fff994ae08d]
    +   27014 _pthread_start  (in libsystem_pthread.dylib) + 286  [0x7fff994ae887]
    +     27014 _pthread_body  (in libsystem_pthread.dylib) + 180  [0x7fff994ae93b]
    +       27014 GC_mark_thread  (in toucan) + 132  [0x109d24458]
    +         27014 GC_help_marker  (in toucan) + 46  [0x109d1e7a6]
    +           27014 GC_wait_marker  (in toucan) + 23  [0x109d25c85]
    +             27014 _pthread_cond_wait  (in libsystem_pthread.dylib) + 712  [0x7fff994af7fa]
    +               27014 __psynch_cvwait  (in libsystem_kernel.dylib) + 10  [0x7fff993c3bf2]
    27014 Thread_288554
    + 19375 thread_start  (in libsystem_pthread.dylib) + 13  [0x7fff994ae08d]
    + ! 19375 _pthread_start  (in libsystem_pthread.dylib) + 286  [0x7fff994ae887]
    + !   19375 _pthread_body  (in libsystem_pthread.dylib) + 180  [0x7fff994ae93b]
    + !     19375 GC_call_with_stack_base  (in toucan) + 26  [0x109d212ee]
    + !       19375 GC_inner_start_routine  (in toucan) + 101  [0x109d2431f]
    + !         19375 ~procProc(Pointer(Void), Pointer(Void))@/usr/local/Cellar/crystal/0.32.1/src/crystal/system/unix/pthread.cr:27  (in toucan) + 13  [0x109a53b6d]
    + !           19375 *Thread#start:(Exception+ | Nil)  (in toucan) + 182  [0x109ac9916]
    + !             19375 ~proc2Proc(Nil)@/usr/local/Cellar/crystal/0.32.1/src/crystal/scheduler.cr:174  (in toucan) + 55  [0x109a53b57]
    + !               19375 *Crystal::Scheduler#run_loop:NoReturn  (in toucan) + 161  [0x109ae4941]
    + !                 19375 *Crystal::FiberChannel#receive:Fiber  (in toucan) + 30  [0x109ae4f3e]
    + !                   19375 *IO::FileDescriptor+@IO#read_bytes<UInt64.class>:UInt64  (in toucan) + 31  [0x109af183f]
    + !                     19375 *UInt64@Int::from_io<IO::FileDescriptor+, IO::ByteFormat::LittleEndian:Module>:UInt64  (in toucan) + 34  [0x109a9f522]
    + !                       19375 *IO::ByteFormat::LittleEndian::decode<UInt64.class, IO::FileDescriptor+>:UInt64  (in toucan) + 56  [0x109afedb8]
    + !                         19375 *IO::FileDescriptor+@IO#read_fully<Slice(UInt8)>:Int32  (in toucan) + 65  [0x109aeee11]
    + !                           19375 *IO::FileDescriptor+@IO#read_fully?<Slice(UInt8)>:(Int32 | Nil)  (in toucan) + 102  [0x109aeeec6]
    + !                             19375 *IO::FileDescriptor+@IO::Buffered#read<Slice(UInt8)>:Int32  (in toucan) + 231  [0x109aef027]
    + !                               19375 *IO::FileDescriptor+@IO::Buffered#fill_buffer:Slice(UInt8)  (in toucan) + 76  [0x109aefb6c]
    + !                                 19375 *IO::FileDescriptor+@Crystal::System::FileDescriptor#unbuffered_read<Slice(UInt8)>:Int32  (in toucan) + 308  [0x109aef284]
    + !                                   19375 *IO::FileDescriptor+@IO::Evented#wait_readable:Nil  (in toucan) + 60  [0x109aef81c]
    + !                                     19375 *IO::FileDescriptor+@IO::Evented#wait_readable<(Time::Span | Nil)>:Nil  (in toucan) + 680  [0x109aefad8]
    + !                                       19375 *Crystal::Scheduler::reschedule:Nil  (in toucan) + 25  [0x109ae3be9]
    + !                                         19375 *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x109ae3c53]
    + !                                           19375 *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x109ae249a]  event_loop_libevent.cr:18
    + !                                             19375 *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x109ae3171]  event_libevent.cr:62
    + !                                               19375 event_base_loop  (in libevent-2.1.7.dylib) + 699  [0x10a5f6343]
    + !                                                 19375 kq_dispatch  (in libevent-2.1.7.dylib) + 559  [0x10a5ff5ba]
    + !                                                   19375 kevent  (in libsystem_kernel.dylib) + 10  [0x7fff993c4d96]
    + 7639 ~proc2Proc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47  (in toucan) + 9  [0x109a537c9]
    +   7639 *Fiber#run:(IO::FileDescriptor | Nil)  (in toucan) + 98  [0x109ac89b2]
    +     7639 ~procProc(Nil)@src/toucan/tunnel/http/proxy.cr:136  (in toucan) + 111  [0x109a5f4af]
    +       7639 *Toucan::Tunnel::Http::Proxy#accept<Socket::Server>:Nil  (in toucan) + 13  [0x109cf232d]
    +         7639 *Toucan::Tunnel::Http::Proxy#accept!<Socket::Server>:Nil  (in toucan) + 163  [0x109cf23f3]
    +           7639 *TCPServer#accept?:(TCPSocket | Nil)  (in toucan) + 21  [0x109c78c45]
    +             7638 *TCPServer@Socket#accept_impl:(Int32 | Nil)  (in toucan) + 148  [0x109c78d74]
    +             : 7638 *TCPServer@IO::Evented#wait_readable:Nil  (in toucan) + 57  [0x109c78dd9]
    +             :   7638 *TCPServer@IO::Evented#wait_readable<(Time::Span | Nil)>:Nil  (in toucan) + 680  [0x109c79088]
    +             :     7638 *Crystal::Scheduler::reschedule:Nil  (in toucan) + 25  [0x109ae3be9]
    +             :       7638 *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x109ae3c53]
    +             :         7638 *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x109ae249a]  event_loop_libevent.cr:18
    +             :           7638 *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x109ae3171]  event_libevent.cr:62
    +             :             7638 event_base_loop  (in libevent-2.1.7.dylib) + 699  [0x10a5f6343]
    +             :               7638 kq_dispatch  (in libevent-2.1.7.dylib) + 559  [0x10a5ff5ba]
    +             :                 7638 kevent  (in libsystem_kernel.dylib) + 10  [0x7fff993c4d96]
    +             1 *TCPServer@Socket#accept_impl:(Int32 | Nil)  (in toucan) + 47  [0x109c78d0f]
    +               1 __accept  (in libsystem_kernel.dylib) + 10  [0x7fff993c30c2]
    27014 Thread_288555
    + 27014 ~proc2Proc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47  (in toucan) + 9  [0x109a537c9]
    +   27014 *Fiber#run:(IO::FileDescriptor | Nil)  (in toucan) + 640  [0x109ac8bd0]
    +     27014 *Crystal::Scheduler::reschedule:Nil  (in toucan) + 25  [0x109ae3be9]
    +       27014 *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x109ae3c53]
    +         27014 *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x109ae249a]  event_loop_libevent.cr:18
    +           27014 *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x109ae3171]  event_libevent.cr:62
    +             27014 event_base_loop  (in libevent-2.1.7.dylib) + 699  [0x10a5f6343]
    +               27014 kq_dispatch  (in libevent-2.1.7.dylib) + 559  [0x10a5ff5ba]
    +                 27014 kevent  (in libsystem_kernel.dylib) + 10  [0x7fff993c4d96]
    27014 Thread_288556
      19375 thread_start  (in libsystem_pthread.dylib) + 13  [0x7fff994ae08d]
      ! 19375 _pthread_start  (in libsystem_pthread.dylib) + 286  [0x7fff994ae887]
      !   19375 _pthread_body  (in libsystem_pthread.dylib) + 180  [0x7fff994ae93b]
      !     19375 GC_call_with_stack_base  (in toucan) + 26  [0x109d212ee]
      !       19375 GC_inner_start_routine  (in toucan) + 101  [0x109d2431f]
      !         19375 ~procProc(Pointer(Void), Pointer(Void))@/usr/local/Cellar/crystal/0.32.1/src/crystal/system/unix/pthread.cr:27  (in toucan) + 13  [0x109a53b6d]
      !           19375 *Thread#start:(Exception+ | Nil)  (in toucan) + 182  [0x109ac9916]
      !             19375 ~proc2Proc(Nil)@/usr/local/Cellar/crystal/0.32.1/src/crystal/scheduler.cr:174  (in toucan) + 55  [0x109a53b57]
      !               19375 *Crystal::Scheduler#run_loop:NoReturn  (in toucan) + 161  [0x109ae4941]
      !                 19375 *Crystal::FiberChannel#receive:Fiber  (in toucan) + 30  [0x109ae4f3e]
      !                   19375 *IO::FileDescriptor+@IO#read_bytes<UInt64.class>:UInt64  (in toucan) + 31  [0x109af183f]
      !                     19375 *UInt64@Int::from_io<IO::FileDescriptor+, IO::ByteFormat::LittleEndian:Module>:UInt64  (in toucan) + 34  [0x109a9f522]
      !                       19375 *IO::ByteFormat::LittleEndian::decode<UInt64.class, IO::FileDescriptor+>:UInt64  (in toucan) + 56  [0x109afedb8]
      !                         19375 *IO::FileDescriptor+@IO#read_fully<Slice(UInt8)>:Int32  (in toucan) + 65  [0x109aeee11]
      !                           19375 *IO::FileDescriptor+@IO#read_fully?<Slice(UInt8)>:(Int32 | Nil)  (in toucan) + 102  [0x109aeeec6]
      !                             19375 *IO::FileDescriptor+@IO::Buffered#read<Slice(UInt8)>:Int32  (in toucan) + 231  [0x109aef027]
      !                               19375 *IO::FileDescriptor+@IO::Buffered#fill_buffer:Slice(UInt8)  (in toucan) + 76  [0x109aefb6c]
      !                                 19375 *IO::FileDescriptor+@Crystal::System::FileDescriptor#unbuffered_read<Slice(UInt8)>:Int32  (in toucan) + 308  [0x109aef284]
      !                                   19375 *IO::FileDescriptor+@IO::Evented#wait_readable:Nil  (in toucan) + 60  [0x109aef81c]
      !                                     19375 *IO::FileDescriptor+@IO::Evented#wait_readable<(Time::Span | Nil)>:Nil  (in toucan) + 680  [0x109aefad8]
      !                                       19375 *Crystal::Scheduler::reschedule:Nil  (in toucan) + 25  [0x109ae3be9]
      !                                         19375 *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x109ae3c53]
      !                                           19375 *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x109ae249a]  event_loop_libevent.cr:18
      !                                             19375 *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x109ae3171]  event_libevent.cr:62
      !                                               19375 event_base_loop  (in libevent-2.1.7.dylib) + 699  [0x10a5f6343]
      !                                                 19375 kq_dispatch  (in libevent-2.1.7.dylib) + 559  [0x10a5ff5ba]
      !                                                   19375 kevent  (in libsystem_kernel.dylib) + 10  [0x7fff993c4d96]
      7639 ~proc2Proc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47  (in toucan) + 9  [0x109a537c9]
        7639 *Fiber#run:(IO::FileDescriptor | Nil)  (in toucan) + 640  [0x109ac8bd0]
          7639 *Crystal::Scheduler::reschedule:Nil  (in toucan) + 25  [0x109ae3be9]
            7639 *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x109ae3c53]
              7639 *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x109ae249a]  event_loop_libevent.cr:18
                7639 *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x109ae3171]  event_libevent.cr:62
                  7639 event_base_loop  (in libevent-2.1.7.dylib) + 699  [0x10a5f6343]
                    7639 kq_dispatch  (in libevent-2.1.7.dylib) + 559  [0x10a5ff5ba]
                      7639 kevent  (in libsystem_kernel.dylib) + 10  [0x7fff993c4d96]

Total number in stack (recursive counted multiple, when >=5):
        6       *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x109ae3171]  event_libevent.cr:62
        6       *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x109ae249a]  event_loop_libevent.cr:18
        6       *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x109ae3c53]
        5       *Crystal::Scheduler::reschedule:Nil  (in toucan) + 25  [0x109ae3be9]
        5       _pthread_body  (in libsystem_pthread.dylib) + 180  [0x7fff994ae93b]
        5       _pthread_start  (in libsystem_pthread.dylib) + 286  [0x7fff994ae887]
        5       event_base_loop  (in libevent-2.1.7.dylib) + 699  [0x10a5f6343]
        5       kevent  (in libsystem_kernel.dylib) + 0  [0x7fff993c4d8c]
        5       kq_dispatch  (in libevent-2.1.7.dylib) + 559  [0x10a5ff5ba]
        5       thread_start  (in libsystem_pthread.dylib) + 13  [0x7fff994ae08d]

Sort by top of stack, same collapsed (when >= 5):
        __psynch_cvwait  (in libsystem_kernel.dylib)        81042
        kevent  (in libsystem_kernel.dylib)        81041
        *Intrinsics::pause:Nil  (in toucan)        24995
        *Crystal::SpinLock#lock:Nil  (in toucan)        1169
        *Atomic(Int32)@Atomic(T)#get:Int32  (in toucan)        850

Binary Images:
       0x109a3c000 -        0x109dbaff7 +toucan (0) <1C7A1269-AA32-3044-9DCB-77AE81236D83> /usr/local/bin/toucan
       0x10a2bb000 -        0x10a30aff3 +libssl.1.1.dylib (0) <DEAC0E01-F7A1-3054-AA76-9BDC5504FF3E> /usr/local/opt/openssl@1.1/lib/libssl.1.1.dylib
       0x10a333000 -        0x10a4f2a53 +libcrypto.1.1.dylib (0) <7AAA983D-49B4-37A5-94D5-D6870CAD4580> /usr/local/opt/openssl@1.1/lib/libcrypto.1.1.dylib
       0x10a58a000 -        0x10a5a2fff +libyaml-0.2.dylib (0) <D64BFABD-6330-3455-AEA3-A051EC3B4B3B> /usr/local/opt/libyaml/lib/libyaml-0.2.dylib
       0x10a5ab000 -        0x10a5d8ff3  libpcre.0.dylib (8) <BCEA4851-21D3-3EFD-B66F-438CC1F96AF3> /usr/lib/libpcre.0.dylib
       0x10a5e3000 -        0x10a5e4fff +libevent_pthreads-2.1.7.dylib (0) <4B335AB9-9974-32C4-AA80-A3F649E4B819> /usr/local/opt/libevent/lib/libevent_pthreads-2.1.7.dylib
       0x10a5e8000 -        0x10a615ff7 +libevent-2.1.7.dylib (0) <E8D7300E-8FE0-33C8-B9C5-DA74B3278FED> /usr/local/opt/libevent/lib/libevent-2.1.7.dylib
       0x113e9f000 -        0x113edcdc7  dyld (0.0 - ???) <322C06B7-8878-311D-888C-C8FD2CA96FF3> /usr/lib/dyld
    0x7fff97ceb000 -     0x7fff97cecffb  libSystem.B.dylib (1238.60.2) <F18AC1E7-C6F1-34B1-8069-BE571B3231D4> /usr/lib/libSystem.B.dylib
    0x7fff97e25000 -     0x7fff97e7bff7  libc++.1.dylib (307.5) <0B43BB5D-E6EB-3464-8DE9-B41AC8ED9D1C> /usr/lib/libc++.1.dylib
    0x7fff97e7c000 -     0x7fff97ea5ff7  libc++abi.dylib (307.4) <BC271AD3-831B-362A-9DA7-E8C51F285FE4> /usr/lib/libc++abi.dylib
    0x7fff982f3000 -     0x7fff983e5ff7  libiconv.2.dylib (50) <42125B35-81D7-3FC4-9475-A26DBE10884D> /usr/lib/libiconv.2.dylib
    0x7fff9899a000 -     0x7fff98d6c047  libobjc.A.dylib (709.1) <70614861-0340-32E2-85ED-FE65759CDFFA> /usr/lib/libobjc.A.dylib
    0x7fff99199000 -     0x7fff991aaff3  libz.1.dylib (67) <46E3FFA2-4328-327A-8D34-A03E20BFFB8E> /usr/lib/libz.1.dylib
    0x7fff991b9000 -     0x7fff991bdff7  libcache.dylib (79) <093A4DAB-8385-3D47-A350-E20CB7CCF7BF> /usr/lib/system/libcache.dylib
    0x7fff991be000 -     0x7fff991c8fff  libcommonCrypto.dylib (60092.50.5) <8A64D1B0-C70E-385C-92F0-E669079FDA90> /usr/lib/system/libcommonCrypto.dylib
    0x7fff991c9000 -     0x7fff991d0fff  libcompiler_rt.dylib (62) <55D47421-772A-32AB-B529-1A46C2F43B4D> /usr/lib/system/libcompiler_rt.dylib
    0x7fff991d1000 -     0x7fff991d9fff  libcopyfile.dylib (138) <819BEA3C-DF11-3E3D-A1A1-5A51C5BF1961> /usr/lib/system/libcopyfile.dylib
    0x7fff991da000 -     0x7fff9925dfdf  libcorecrypto.dylib (442.50.19) <65D7165E-2E71-335D-A2D6-33F78E2DF0C1> /usr/lib/system/libcorecrypto.dylib
    0x7fff9925e000 -     0x7fff9928ffff  libdispatch.dylib (703.50.37) <6582BAD6-ED27-3B30-B620-90B1C5A4AE3C> /usr/lib/system/libdispatch.dylib
    0x7fff99290000 -     0x7fff99295ffb  libdyld.dylib (433.5) <9B2AC56D-107C-3541-A127-9094A751F2C9> /usr/lib/system/libdyld.dylib
    0x7fff99296000 -     0x7fff99296ffb  libkeymgr.dylib (28) <7AA011A9-DC21-3488-BF73-3B5B14D1FDD6> /usr/lib/system/libkeymgr.dylib
    0x7fff992a4000 -     0x7fff992a4fff  liblaunch.dylib (972.70.1) <B856ABD2-896E-3DE0-B2C8-146A6AF8E2A7> /usr/lib/system/liblaunch.dylib
    0x7fff992a5000 -     0x7fff992aaff3  libmacho.dylib (898) <17D5D855-F6C3-3B04-B680-E9BF02EF8AED> /usr/lib/system/libmacho.dylib
    0x7fff992ab000 -     0x7fff992adff3  libquarantine.dylib (85.50.1) <12448CC2-378E-35F3-BE33-9DC395A5B970> /usr/lib/system/libquarantine.dylib
    0x7fff992ae000 -     0x7fff992afffb  libremovefile.dylib (45) <38D4CB9C-10CD-30D3-8B7B-A515EC75FE85> /usr/lib/system/libremovefile.dylib
    0x7fff992b0000 -     0x7fff992c8ff7  libsystem_asl.dylib (349.50.5) <096E4228-3B7C-30A6-8B13-EC909A64499A> /usr/lib/system/libsystem_asl.dylib
    0x7fff992c9000 -     0x7fff992c9ff7  libsystem_blocks.dylib (67) <10DC5404-73AB-35B3-A277-A8AFECB476EB> /usr/lib/system/libsystem_blocks.dylib
    0x7fff992ca000 -     0x7fff99357fef  libsystem_c.dylib (1158.50.2) <E5AE5244-7D0C-36AC-8BB6-C7AE7EA52A4B> /usr/lib/system/libsystem_c.dylib
    0x7fff99358000 -     0x7fff9935bffb  libsystem_configuration.dylib (888.60.2) <BECC01A2-CA8D-31E6-BCDF-D452965FA976> /usr/lib/system/libsystem_configuration.dylib
    0x7fff9935c000 -     0x7fff9935ffff  libsystem_coreservices.dylib (41.4) <7D26DE79-B424-3450-85E1-F7FAB32714AB> /usr/lib/system/libsystem_coreservices.dylib
    0x7fff99360000 -     0x7fff99378fff  libsystem_coretls.dylib (121.50.4) <EC6FCF07-DCFB-3A03-9CC9-6DD3709974C6> /usr/lib/system/libsystem_coretls.dylib
    0x7fff99379000 -     0x7fff9937ffff  libsystem_dnssd.dylib (765.50.9) <CC960215-0B1B-3822-A13A-3DDE96FA796F> /usr/lib/system/libsystem_dnssd.dylib
    0x7fff99380000 -     0x7fff993a9ff7  libsystem_info.dylib (503.50.4) <611DB84C-BF70-3F92-8702-B9F28A900920> /usr/lib/system/libsystem_info.dylib
    0x7fff993aa000 -     0x7fff993ccff7  libsystem_kernel.dylib (3789.70.16) <34B1F16C-BC9C-3C5F-9045-0CAE91CB5914> /usr/lib/system/libsystem_kernel.dylib
    0x7fff993cd000 -     0x7fff99414fe7  libsystem_m.dylib (3121.6) <86D499B5-BBDC-3D3B-8A4E-97AE8E6672A4> /usr/lib/system/libsystem_m.dylib
    0x7fff99415000 -     0x7fff99433ff7  libsystem_malloc.dylib (116.50.8) <A3D15F17-99A6-3367-8C7E-4280E8619C95> /usr/lib/system/libsystem_malloc.dylib
    0x7fff99434000 -     0x7fff9948dffb  libsystem_network.dylib (856.60.1) <369D0221-56CA-3C3E-9EDE-94B41CAE77B7> /usr/lib/system/libsystem_network.dylib
    0x7fff9948e000 -     0x7fff99497ff3  libsystem_networkextension.dylib (563.60.2) <B021F2B3-8A75-3633-ABB0-FC012B8E9B0C> /usr/lib/system/libsystem_networkextension.dylib
    0x7fff99498000 -     0x7fff994a1ff3  libsystem_notify.dylib (165.20.1) <B8160190-A069-3B3A-BDF6-2AA408221FAE> /usr/lib/system/libsystem_notify.dylib
    0x7fff994a2000 -     0x7fff994aafe7  libsystem_platform.dylib (126.50.8) <897462FD-B318-321B-A554-E61982630F7E> /usr/lib/system/libsystem_platform.dylib
    0x7fff994ab000 -     0x7fff994b5ff7  libsystem_pthread.dylib (218.60.3) <B8FB5E20-3295-39E2-B5EB-B464D1D4B104> /usr/lib/system/libsystem_pthread.dylib
    0x7fff994b6000 -     0x7fff994b9ff7  libsystem_sandbox.dylib (592.70.1) <4B92EC49-ACD0-36AE-B07A-A2B8152EAF9D> /usr/lib/system/libsystem_sandbox.dylib
    0x7fff994ba000 -     0x7fff994bbff3  libsystem_secinit.dylib (24.50.4) <F78B847B-3565-3E4B-98A6-F7AD40392E2D> /usr/lib/system/libsystem_secinit.dylib
    0x7fff994bc000 -     0x7fff994c3ffb  libsystem_symptoms.dylib (532.50.47) <3390E07C-C1CE-348F-ADBD-2C5440B45EAA> /usr/lib/system/libsystem_symptoms.dylib
    0x7fff994c4000 -     0x7fff994d7ff7  libsystem_trace.dylib (518.70.1) <AC63A7FE-50D9-3A30-96E6-F6B7FF16E465> /usr/lib/system/libsystem_trace.dylib
    0x7fff994d8000 -     0x7fff994ddffb  libunwind.dylib (35.3) <3D50D8A8-C460-334D-A519-2DA841102C6B> /usr/lib/system/libunwind.dylib
    0x7fff994de000 -     0x7fff99507ff7  libxpc.dylib (972.70.1) <BF896DF0-D8E9-31A8-A4B3-01120BFEEE52> /usr/lib/system/libxpc.dylib
  • Normal
Call graph:
    2252 Thread_314067   DispatchQueue_1: com.apple.main-thread  (serial)
    + 2252 ~procProc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47  (in toucan) + 9  [0x10339bb39]  fiber.cr:47
    +   2252 *Fiber#run:(IO::FileDescriptor | Nil)  (in toucan) + 83  [0x103410e53]  fiber.cr:255
    +     2252 ~procProc(Nil)@/usr/local/Cellar/crystal/0.32.1/src/kernel.cr:542  (in toucan) + 24  [0x10339ba18]  kernel.cr:542
    +       2252 *sleep<Int32>:Nil  (in toucan) + 66  [0x10339ba72]  concurrent.cr:15
    +         2252 *Crystal::Scheduler::sleep<Time::Span>:Nil  (in toucan) + 57  [0x10342c8f9]  scheduler.cr:52
    +           2252 *Crystal::Scheduler#sleep<Time::Span>:Nil  (in toucan) + 84  [0x10342c954]  scheduler.cr:162
    +             2252 *Crystal::Scheduler#reschedule:Nil  (in toucan) + 99  [0x10342c0e3]  scheduler.cr:151
    +               2252 *Crystal::EventLoop::run_once:Int32  (in toucan) + 26  [0x10342a92a]  event_loop_libevent.cr:18
    +                 2252 *Crystal::Event::Base#run_once:Int32  (in toucan) + 17  [0x10342b601]  event_libevent.cr:62
    +                   2252 event_base_loop  (in libevent-2.1.7.dylib) + 699  [0x103f35343]
    +                     2252 kq_dispatch  (in libevent-2.1.7.dylib) + 559  [0x103f3e5ba]
    +                       2252 kevent  (in libsystem_kernel.dylib) + 10  [0x7fff993c4d96]

Crashes

Invalid memory access (signal 11) at address 0xfffffffe946179e0
[0x1090f6f2b] *CallStack::print_backtrace:Int32 +107
[0x1090ad6e6] __crystal_sigfault_handler +198
[0x7fff8b1b6b3a] _sigtramp +26
[0x1091366fe] *Pointer(Hash::Entry(Thread, Deque(Fiber)))@Pointer(T)#[]<Int32>:Hash::Entry(Thread, Deque(Fiber)) +14
[0x10913524f] *Hash(Thread, Deque(Fiber))@Hash(K, V)#get_entry<Int32>:Hash::Entry(Thread, Deque(Fiber)) +31
[0x109134cca] *Hash(Thread, Deque(Fiber))@Hash(K, V)#find_entry<Thread>:(Hash::Entry(Thread, Deque(Fiber)) | Nil) +474
[0x109134a7c] *Hash(Thread, Deque(Fiber))@Hash(K, V)#fetch<Thread, Nil>:(Deque(Fiber) | Nil) +44
[0x109134a49] *Hash(Thread, Deque(Fiber))@Hash(K, V)#[]?<Thread>:(Deque(Fiber) | Nil) +9
[0x10913487a] *Crystal::ThreadLocalValue(Deque(Fiber))@Crystal::ThreadLocalValue(T)#get?:(Deque(Fiber) | Nil) +106
[0x1091defde] *Socket+@IO::Evented#resume_read<Bool>:Nil +46
[0x1090b09d5] ~proc4Proc(Int32, LibEvent2::EventFlags, Pointer(Void), Nil)@/usr/local/Cellar/crystal/0.32.1/src/crystal/system/unix/event_loop_libevent.cr:52 +101
[0x109c2efe7] event_process_active_single_queue +383
[0x109c2c4ba] event_base_loop +1074
[0x10913bca1] *Crystal::Event::Base#run_once:Int32 +17
[0x10913afca] *Crystal::EventLoop::run_once:Int32 +26
[0x10913c783] *Crystal::Scheduler#reschedule:Nil +99
[0x10913c719] *Crystal::Scheduler::reschedule:Nil +25
[0x1091df338] *Socket+@IO::Evented#wait_readable<(Time::Span | Nil)>:Nil +680
[0x1091df089] *Socket+@IO::Evented#wait_readable:Nil +57
[0x1091deafc] *Socket+@Socket#unbuffered_read<Slice(UInt8)>:Int32 +348
[0x1091df43e] *Socket+@IO::Buffered#read<Slice(UInt8)>:Int32 +190
[0x109140788] *IO::copy<Socket+, IO+>:UInt64 +104
[0x1090b870f] ~procProc(Nil)@src/toucan/tunnel/http/processor.cr:345 +31
[0x109121502] *Fiber#run:(IO::FileDescriptor | Nil) +98
[0x1090acbf9] ~proc2Proc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47 +9
Invalid memory access (signal 11) at address 0x52574c53
[0x10b5cc1db] *CallStack::print_backtrace:Int32 +107
[0x10b581916] __crystal_sigfault_handler +198
[0x7fffbd5c9b3a] _sigtramp +26
[0x10c151adc] event_queue_remove_active_later +94
[0x10c14ece0] event_del_nolock_ +189
[0x10c150392] event_base_loop +778
[0x10b610ef1] *Crystal::Event::Base#run_once:Int32 +17
[0x10b61021a] *Crystal::EventLoop::run_once:Int32 +26
[0x10b6119d3] *Crystal::Scheduler#reschedule:Nil +99
[0x10b611969] *Crystal::Scheduler::reschedule:Nil +25
[0x10b6d7358] *TCPSocket+@IO::Evented#wait_readable<(Time::Span | Nil)>:Nil +680
[0x10b6d70a9] *TCPSocket+@IO::Evented#wait_readable:Nil +57
[0x10b6d6b1c] *TCPSocket+@Socket#unbuffered_read<Slice(UInt8)>:Int32 +348
[0x10b6d73ec] *TCPSocket+@IO::Buffered#fill_buffer:Slice(UInt8) +76
[0x10b6d6897] *TCPSocket+@IO::Buffered#read<Slice(UInt8)>:Int32 +231
[0x10b6d6077] *MITM::Extract#read<Slice(UInt8)>:Int32 +87
[0x10b6ba530] *IO::Stapled#read<Slice(UInt8)>:Int32 +160
[0x10b585b44] ~procProc(Pointer(LibCrypto::Bio), Pointer(UInt8), UInt64, Pointer(UInt64), Int32)@/usr/local/Cellar/crystal/0.32.1/src/openssl/bio.cr:42 +1684
[0x10bedcb53] bio_read_intern +138
[0x10bedcaba] BIO_read +25
[0x10be3d7e0] ssl3_read_n +628
[0x10be3fed5] ssl3_get_record +205
[0x10be3eea1] ssl3_read_bytes +473
[0x10be46da0] ssl3_read_internal +110
[0x10be50209] SSL_read +25
[0x10b6a4ecf] *OpenSSL::SSL::SuperSocket+@OpenSSL::SSL::SuperSocket#unbuffered_read<Slice(UInt8)>:Int32 +159
[0x10b6a22ad] *OpenSSL::SSL::Socket+@IO::Buffered#read<Slice(UInt8)>:Int32 +317
[0x10b61647d] *IO::copy<IO+, Socket+>:UInt64 +893
[0x10b58d972] ~procProc(Nil)@src/toucan/tunnel/http/processor.cr:341 +34
[0x10b5f6752] *Fiber#run:(IO::FileDescriptor | Nil) +98
[0x10b580e29] ~proc2Proc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47 +9

Lsof

COMMAND  PID USER   FD     TYPE            DEVICE  SIZE/OFF     NODE NAME
toucan  2907 User  cwd      DIR               1,2      2448   443608 /Users/User
toucan  2907 User  txt      REG               1,2   6680244  4266838 /usr/local/bin/toucan
toucan  2907 User  txt      REG               1,2    490052  9621873 /usr/local/Cellar/openssl@1.1/1.1.1d/lib/libssl.1.1.dylib
toucan  2907 User  txt      REG               1,2   2416296  9621870 /usr/local/Cellar/openssl@1.1/1.1.1d/lib/libcrypto.1.1.dylib
toucan  2907 User  txt      REG               1,2    114108  5487905 /usr/local/Cellar/libyaml/0.2.2/lib/libyaml-0.2.dylib
toucan  2907 User  txt      REG               1,2    416976   422220 /usr/lib/libpcre.0.dylib
toucan  2907 User  txt      REG               1,2     14352  9630926 /usr/local/Cellar/libevent/2.1.11_1/lib/libevent_pthreads-2.1.7.dylib
toucan  2907 User  txt      REG               1,2    248404  9630914 /usr/local/Cellar/libevent/2.1.11_1/lib/libevent-2.1.7.dylib
toucan  2907 User  txt      REG               1,2    698896   422030 /usr/lib/dyld
toucan  2907 User  txt      REG               1,2 662372352 15116458 /private/var/db/dyld/dyld_shared_cache_x86_64h
toucan  2907 User    0u     CHR              16,5    0t1268     1131 /dev/ttys005
toucan  2907 User    1u     CHR              16,5    0t1268     1131 /dev/ttys005
toucan  2907 User    2u     CHR              16,5    0t1268     1131 /dev/ttys005
toucan  2907 User    3     PIPE 0xe2bdcf106a33665     16384          ->0xe2bdcf106a334e5
toucan  2907 User    4     PIPE 0xe2bdcf106a334e5     16384          ->0xe2bdcf106a33665
toucan  2907 User    5r     CHR              14,1   0t14048      574 /dev/urandom
toucan  2907 User    6u     CHR              16,5       0t0     1131 /dev/ttys005
toucan  2907 User    7u     CHR              16,5  0t866992     1131 /dev/ttys005
toucan  2907 User    8u     CHR              16,5       0t0     1131 /dev/ttys005
toucan  2907 User    9     PIPE 0xe2bdcf106a32ee5     16384          ->0xe2bdcf106a332a5
toucan  2907 User   10     PIPE 0xe2bdcf106a332a5     16384          ->0xe2bdcf106a32ee5
toucan  2907 User   11     PIPE 0xe2bdcf106a33965     16384          ->0xe2bdcf106a33a25
toucan  2907 User   12     PIPE 0xe2bdcf106a33a25     16384          ->0xe2bdcf106a33965
toucan  2907 User   13u  KQUEUE                                      count=0, state=0xa
toucan  2907 User   14     PIPE 0xe2bdcf106a338a5     16384          ->0xe2bdcf106a30ea5
toucan  2907 User   15     PIPE 0xe2bdcf106a30ea5     16384          ->0xe2bdcf106a338a5
toucan  2907 User   16u  KQUEUE                                      count=4, state=0x8
toucan  2907 User   17     PIPE 0xe2bdcf106a30d25     16384          ->0xe2bdcf106a311a5
toucan  2907 User   18     PIPE 0xe2bdcf106a311a5     16384          ->0xe2bdcf106a30d25
toucan  2907 User   19u  KQUEUE                                      count=0, state=0xa
toucan  2907 User   20u  KQUEUE                                      count=0, state=0xa
toucan  2907 User   21w     REG               1,2    866992 17943369 /Users/User/Toucan/Logging/Tunnel/Http/TCP/2020.01.24/19_08_56/C6CB3A.log
toucan  2907 User   22u    IPv4 0xe2bdcf10bdfae95       0t0      TCP *:search-agent (LISTEN)
toucan  2907 User   23u    IPv4 0xe2bdcf10bfa778d       0t0      TCP localhost:search-agent->localhost:62191 (CLOSE_WAIT)
toucan  2907 User   24u    IPv4 0xe2bdcf11d3f6e95       0t0      TCP localhost:search-agent->localhost:62151 (CLOSE_WAIT)
toucan  2907 User   25u    IPv4 0xe2bdcf1161d5e95       0t0      TCP localhost:search-agent->localhost:62263 (ESTABLISHED)
toucan  2907 User   26u    IPv4 0xe2bdcf10440f78d       0t0      TCP localhost:search-agent->localhost:62197 (CLOSE_WAIT)
toucan  2907 User   27u    IPv4 0xe2bdcf110141e95       0t0      TCP localhost:search-agent->localhost:61890 (CLOSE_WAIT)
toucan  2907 User   28u    unix 0xe2bdcf116205c6d       0t0          ->(none)
toucan  2907 User   29u    IPv4 0xe2bdcf1043ad1bd       0t0      TCP localhost:search-agent->localhost:62206 (CLOSE_WAIT)
toucan  2907 User   30u    IPv4 0xe2bdcf10bdfb78d       0t0      TCP localhost:search-agent->localhost:62269 (CLOSE_WAIT)
toucan  2907 User   31u    IPv4 0xe2bdcf116d881bd       0t0      TCP localhost:search-agent->localhost:62241 (CLOSE_WAIT)
toucan  2907 User   32u    IPv4 0xe2bdcf11fa6678d       0t0      TCP localhost:search-agent->localhost:62231 (ESTABLISHED)
toucan  2907 User   33u    IPv4 0xe2bdcf116dcdca5       0t0      TCP 192.168.1.100:62242->17.248.161.164:https (CLOSE_WAIT)
toucan  2907 User   34u    IPv4 0xe2bdcf11069d3ad       0t0      TCP localhost:search-agent->localhost:59028 (CLOSE_WAIT)
toucan  2907 User   35u    IPv4 0xe2bdcf1169eae95       0t0      TCP localhost:search-agent->localhost:62253 (CLOSE_WAIT)
toucan  2907 User   36u    IPv4 0xe2bdcf10d17959d       0t0      TCP localhost:search-agent->localhost:59029 (CLOSE_WAIT)
toucan  2907 User   37u    IPv4 0xe2bdcf1169e93ad       0t0      TCP localhost:search-agent->localhost:62184 (CLOSE_WAIT)
toucan  2907 User   38u    IPv4 0xe2bdcf116226ab5       0t0      TCP localhost:search-agent->localhost:62210 (CLOSE_WAIT)
toucan  2907 User   39u    IPv4 0xe2bdcf108c1278d       0t0      TCP localhost:search-agent->localhost:62211 (CLOSE_WAIT)
toucan  2907 User   40u    IPv4 0xe2bdcf10442be95       0t0      TCP localhost:search-agent->localhost:59033 (CLOSE_WAIT)
toucan  2907 User   41u    unix 0xe2bdcf1162089bd       0t0          ->(none)
toucan  2907 User   42u    IPv4 0xe2bdcf11064e59d       0t0      TCP localhost:search-agent->localhost:62275 (CLOSE_WAIT)
toucan  2907 User   43u    IPv4 0xe2bdcf11622359d       0t0      TCP localhost:search-agent->localhost:62235 (CLOSE_WAIT)
toucan  2907 User   44u    IPv4 0xe2bdcf116a0459d       0t0      TCP localhost:search-agent->localhost:62284 (ESTABLISHED)
toucan  2907 User   45u    unix 0xe2bdcf11620869d       0t0          ->(none)
toucan  2907 User   46u    unix 0xe2bdcf11620611d       0t0          ->(none)
toucan  2907 User   47u    unix 0xe2bdcf116206cd5       0t0          ->(none)
toucan  2907 User   48u    IPv4 0xe2bdcf1169ace95       0t0      TCP localhost:search-agent->localhost:59042 (CLOSE_WAIT)
toucan  2907 User   49u    IPv4 0xe2bdcf110632ca5       0t0      TCP localhost:search-agent->localhost:62286 (ESTABLISHED)
toucan  2907 User   50u    IPv4 0xe2bdcf11d434ab5       0t0      TCP localhost:search-agent->localhost:62226 (CLOSE_WAIT)
toucan  2907 User   51u    IPv4 0xe2bdcf116e13ab5       0t0      TCP localhost:search-agent->localhost:62289 (ESTABLISHED)
toucan  2907 User   52u    IPv4 0xe2bdcf11d28c78d       0t0      TCP localhost:search-agent->localhost:59046 (CLOSE_WAIT)
toucan  2907 User   54u    IPv4 0xe2bdcf10442a3ad       0t0      TCP 192.168.1.100:62287->[...]:https (ESTABLISHED)
toucan  2907 User   58u    unix 0xe2bdcf1162077c5       0t0          ->(none)
toucan  2907 User   59u    unix 0xe2bdcf11620882d       0t0          ->(none)
toucan  2907 User   60u    unix 0xe2bdcf116207ae5       0t0          ->(none)
toucan  2907 User   64u    IPv4 0xe2bdcf11d41a3ad       0t0      TCP localhost:search-agent->localhost:59088 (CLOSE_WAIT)
toucan  2907 User   70u    IPv4 0xe2bdcf104429ab5       0t0      TCP localhost:search-agent->localhost:59096 (CLOSE_WAIT)
toucan  2907 User   74u    unix 0xe2bdcf11d3b856d       0t0          ->(none)
toucan  2907 User   77u    unix 0xe2bdcf1162085d5       0t0          ->(none)
toucan  2907 User   86u    IPv4 0xe2bdcf110633e95       0t0      TCP localhost:search-agent->localhost:59120 (CLOSE_WAIT)
toucan  2907 User   88u    IPv4 0xe2bdcf11626e78d       0t0      TCP localhost:search-agent->localhost:62138 (ESTABLISHED)
toucan  2907 User   89u    IPv4 0xe2bdcf108c1159d       0t0      TCP localhost:search-agent->localhost:61805 (CLOSE_WAIT)
toucan  2907 User   91u    unix 0xe2bdcf11d3b8315       0t0          ->(none)
toucan  2907 User  102u    IPv4 0xe2bdcf116e5d59d       0t0      TCP localhost:search-agent->localhost:59881 (CLOSE_WAIT)
toucan  2907 User  104u    unix 0xe2bdcf11d3b6d35       0t0          ->(none)
toucan  2907 User  112u    IPv4 0xe2bdcf10cd1cab5       0t0      TCP localhost:search-agent->localhost:61032 (CLOSE_WAIT)
toucan  2907 User  114u    unix 0xe2bdcf11d3b9765       0t0          ->(none)
toucan  2907 User  117u    IPv4 0xe2bdcf10ceb93ad       0t0      TCP localhost:search-agent->localhost:61545 (CLOSE_WAIT)
toucan  2907 User  120u    IPv4 0xe2bdcf10dc553ad       0t0      TCP localhost:search-agent->localhost:61994 (CLOSE_WAIT)
toucan  2907 User  121u    unix 0xe2bdcf11d3b743d       0t0          ->(none)
toucan  2907 User  125u    unix 0xe2bdcf10e71eba5       0t0          ->(none)
toucan  2907 User  129u    unix 0xe2bdcf10e720e05       0t0          ->(none)
toucan  2907 User  141u    IPv4 0xe2bdcf1161f2ab5       0t0      TCP localhost:search-agent->localhost:59226 (CLOSE_WAIT)
toucan  2907 User  145u    IPv4 0xe2bdcf1106e078d       0t0      TCP localhost:search-agent->localhost:59230 (CLOSE_WAIT)
toucan  2907 User  148u    IPv4 0xe2bdcf116223e95       0t0      TCP localhost:search-agent->localhost:61629 (CLOSE_WAIT)
toucan  2907 User  151u    unix 0xe2bdcf10e71fa7d       0t0          ->(none)
toucan  2907 User  152u    unix 0xe2bdcf10e71f2ad       0t0          ->(none)

Version

  • Crystal
User$ crystal -v
Crystal 0.32.1 (2019-12-31)

LLVM: 9.0.0
Default target: x86_64-apple-macosx
  • macOS
macOS Sierra 10.12.6
@bcardiff
Copy link
Member

It seems similar to something I described in #8707

From the trace, I assume the http server performs some Process.run, am I right?
Did you experience this issue without preview_mt at some point?

@636f7374
Copy link
Author

636f7374 commented Jan 24, 2020

@bcardiff


From the trace, I assume the http server performs some Process.run, am I right?

No, just the MITM server, and using IPC (UNIXSocket) to connect remote.
(I will try later.)


Did you experience this issue without preview_mt at some point?

I haven't tried it yet, but there should be no problems, this doesn't happen often, every error happens only once. (Every error / crash was encountered only once).

Normal situation (4-5 hours running) No memory leak / socket leak.
(I intermittently ran the MITM server for a week (via Automator)).


  • Part of the Source Code
    def transport(client, server : IO)
      logger.try &.transporting
      upgrade_proxy server

      if client.responds_to? :skip_free=
        client.skip_free = true
      end

      begin
        attach_message client, server
      rescue ex
        client.close rescue nil
        server.close rescue nil
        return tls_free client
      end

      all_transport client, server
    end

    def all_transport(client, server : IO)
      channel = Channel(Bool).new

      spawn do
        IO.copy client, server rescue nil
        channel.send true
      end

      spawn do
        IO.copy server, client rescue nil
        channel.send true
      end

      if channel.receive
        client.close rescue nil
        server.close rescue nil
      end

      if channel.receive
        tls_free client
        logger.try &.finished
      end
    end

@636f7374
Copy link
Author

@bcardiff Remove the preview_mt program without any problems / errors.

@rdp
Copy link
Contributor

rdp commented Jan 29, 2020

simplified test case would help...what libevent version? what does the call graph have to do with the crashes? That was the hang? Might be interesting to run it within gdb/lldb so that when it crashes you can get a stack trace on all current threads... (thread apply all bt in gdb land...FWIW)

@636f7374
Copy link
Author

@rdp

The message you are asking about is mentioned on this question.

simplified test case would help...what libevent version?

Binary Images:
       0x109a3c000 -        0x109dbaff7 +toucan (0) <1C7A1269-AA32-3044-9DCB-77AE81236D83> /usr/local/bin/toucan
       0x10a2bb000 -        0x10a30aff3 +libssl.1.1.dylib (0) <DEAC0E01-F7A1-3054-AA76-9BDC5504FF3E> /usr/local/opt/openssl@1.1/lib/libssl.1.1.dylib
       0x10a333000 -        0x10a4f2a53 +libcrypto.1.1.dylib (0) <7AAA983D-49B4-37A5-94D5-D6870CAD4580> /usr/local/opt/openssl@1.1/lib/libcrypto.1.1.dylib
       0x10a58a000 -        0x10a5a2fff +libyaml-0.2.dylib (0) <D64BFABD-6330-3455-AEA3-A051EC3B4B3B> /usr/local/opt/libyaml/lib/libyaml-0.2.dylib
       0x10a5ab000 -        0x10a5d8ff3  libpcre.0.dylib (8) <BCEA4851-21D3-3EFD-B66F-438CC1F96AF3> /usr/lib/libpcre.0.dylib
       0x10a5e3000 -        0x10a5e4fff +libevent_pthreads-2.1.7.dylib (0) <4B335AB9-9974-32C4-AA80-A3F649E4B819> /usr/local/opt/libevent/lib/libevent_pthreads-2.1.7.dylib
       0x10a5e8000 -        0x10a615ff7 +libevent-2.1.7.dylib (0) <E8D7300E-8FE0-33C8-B9C5-DA74B3278FED> /usr/local/opt/libevent/lib/libevent-2.1.7.dylib

what does the call graph have to do with the crashes?

Just simple IO.copy

And two related crashes that were triggered earlier.
In addition lsof (UNIXSocket) will appear (none).
This problem only happens occasionally.
The server encounters this problem and will slowly process the client, and a hang issue occurs.

Running 20 times can appear 2-3 times (each execution time is 1-3 hours).

The message you are asking about is mentioned on this question.


That was the hang? Might be interesting to run it within gdb/lldb so that when it crashes you can get a stack trace on all current threads... (thread apply all bt in gdb land...FWIW)

This is a server (MITM Server).

I am convinced that #8707 can solve this problem.

:)

@636f7374
Copy link
Author

Update

Waiting #8707 fixed.

  • Crash
Invalid memory access (signal 11) at address 0x0
[0x1008b68ab] *CallStack::print_backtrace:Int32 +107
[0x10086cb76] __crystal_sigfault_handler +198
[0x7fffa0627b3a] _sigtramp +26
[0x101446969] event_queue_remove_active +94
[0x101443cf5] event_del_nolock_ +210
[0x101446a1d] event_del_ +60
[0x101445ebf] event_free +19
[0x10090bba2] *Crystal::Event#free:Bool +34
[0x1009066d2] *IO::FileDescriptor@IO::Evented#evented_close:Hash(Thread, Deque(Fiber)) +1490
[0x10090606c] *IO::FileDescriptor@Crystal::System::FileDescriptor#system_close:Nil +60
[0x100905ff3] *IO::FileDescriptor#unbuffered_close:Nil +35
[0x100905fbc] *IO::FileDescriptor@IO::Buffered#close:Nil +108
[0x100b3cb5c] *Toucan::Relay::Http::Response#set_stream_body:(IO+ | Int32 | Nil) +780
[0x100a77acf] *Toucan::Relay::Http::Server#call<HTTP::Server::Context>:(IO+ | Int32 | Nil) +110975
[0x100ac724b] *HTTP::Server::RequestProcessor#process<IO+, IO+, IO::FileDescriptor>:Nil +2411
[0x100ac68d5] *HTTP::Server::RequestProcessor#process<IO+, IO+>:Nil +53
[0x100ac5f2b] *HTTP::Server#handle_client<Socket::Server, IO+>:Nil +315
[0x100875dda] ~procProc(Nil)@lib/cherry/src/cherry/http/server.cr:63 +26
[0x1008e0ff2] *Fiber#run:(IO::FileDescriptor | Nil) +98
[0x10086c089] ~proc2Proc(Fiber, (IO::FileDescriptor | Nil))@/usr/local/Cellar/crystal/0.32.1/src/fiber.cr:47 +9

@636f7374
Copy link
Author

636f7374 commented Jan 29, 2020

I'll test it later #8707. :)

@rdp
Copy link
Contributor

rdp commented Feb 10, 2020

Maybe after #8733

@636f7374
Copy link
Author

636f7374 commented Feb 11, 2020

@rdp Sorry buddy, I have been making SOCKS5 Server / Client these days, Forgot to test if this fixes the problem (Pull #8707 and #8733) :)
SOCKS5 Client / Server is now completed. 🚧 WIP - Crystal SOCKS5 Client with Server

Now, I'm going to test if Pull solves the problem, Also encountered a new problem a few days ago, related to this.

[err] event_queue_remove_active: 0x7f9682f04c50 not on queue 8

@rdp
Copy link
Contributor

rdp commented Feb 12, 2020 via email

@636f7374
Copy link
Author

@rdp OKay, I will try to enable libevent debug. In addition, if version 0.33 is released, I will test all the above problem. I will close this issue for the time being. If there are any new findings, I will write some of the details as much as possible, Thank you for your help :) 🙏

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants