Ruby Net :: OpenTimeout при вызове 'put', странная трассировка стека.Многопоточное приложение - PullRequest
Новая
       8

Ruby Net :: OpenTimeout при вызове 'put', странная трассировка стека.Многопоточное приложение

0 голосов
/ 07 февраля 2019

У меня есть 2 приведенных ниже стека трассировки из моего приложения Ruby.

Первая трассировка стека показывает исключение, которое будет сгенерировано в строке 161 моего файла http.rb.В строке 161 есть вызов put () , как вы можете видеть в моем фрагменте кода ниже исключения.Трассировка стека также показывает вызов write () , который, как я полагаю, является вызовом низкого уровня C.Трассировка второго стека также предназначена для put () , но в другой части приложения.Эта строка на самом деле просто временная отладочная информация.Здесь вы можете видеть, что мы используем Monitor для синхронизации некоторых журналов, потому что это многопоточное приложение.

Исключением является исключение Net :: OpenTimeout.В другом месте у меня есть код, который выполняет сетевые подключения, а в других местах есть обработчик исключений для их перехвата.

Как может вызов 'put' привести к исключению Net :: Timeout?

Может ли быть что-то смешное с файловыми дескрипторами?

Net :: OpenTimeout , "срок выполнения истек", "[\" / Users / tomburnell /github / lemonitor / lib / мониторинг / проверок / http.rb: 161: в ' запись ' \ ", \" / Users / tomburnell / github / lemonitor / lib / мониторинг / проверок / http.rb:161: в ' помещает ' \ ", \" / Users / tomburnell / github / lemonitor / lib / мониторинг / проверок / http.rb: 161: в 'put' \ ", \" / Users /tomburnell / github / lemonitor / lib / мониторинг / проверок / http.rb: 161: в 'logResult' \ ", \" / Users / tomburnell / github / лимонитор / lib / мониторинг / проверок / generic.rb: 65: in 'rescue в call_check '\ ", \" / Users / tomburnell / github / lemonitor / lib / мониторинг / проверок / generic.rb: 63: в' call_check '\ ", \" / Users / tomburnell / github / lemonitor / lib /мониторинг / проверок / generic.rb: 46: в блоке яn schedule '\ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler / jobs.rb: 218: в' do_call '\ ", \" / Users /tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler / jobs.rb: 262: в 'trigger_now' \ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler / jobs.rb: 307: в блоке (3 уровня) в start_work_thread '\ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib/rufus/scheduler/jobs.rb:310:in 'блок (2 уровня) в start_work_thread' \ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler /jobs.rb: 296: in 'loop' \ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler / jobs.rb: 296: in 'в блоке start_work_thread'\ "]", 

   if !passed && @@previous_double_check.key?(@key) && !@@previous_double_check[@key]
      puts "#{@key} failed after double check"
      _passed=false
   elsif !passed 
     puts "#{@key} first attempt failed, but marking true"      # line 161           
      opts[:failedPendingDoubleCheck] = true
      _passed=true
   end

Net :: OpenTimeout, "срок выполнения истек", "[\" lib / мониторинг / monitor.rb: 209: в write'\", \"lib/monitoring/monitor.rb:209:in помещает '\ ", \" lib / monitor / monitor.rb: 209: в блок puts'\", \"lib/monitoring/monitor.rb:209:in (2 уровня) в do_check' \ ", \" lib / monitor / monitor.rb: 208: в synchronize'\", \"lib/monitoring/monitor.rb:208:inблок в do_check '\ ", \" / Users / tomburnell / github / lemonitor / lib / мониторинг / проверок / generic.rb: 93: в logResult'\", \"/Users/tomburnell/github/lemonitor/lib/monitoring/checks/http.rb:170:in logResult '\ ", \" / Users / tomburnell / github / lemonitor / lib / мониторинг / проверок / generic.rb: 65: в rescue in call_check'\", \"/Users/tomburnell/github/lemonitor/lib/monitoring/checks/generic.rb:63:in call_check '\ ", \" / Users / tomburnell / github / lemonitor / lib / мониторинг / проверок / generic.rb: 46: in block in schedule'\", \"/Users/tomburnell/.gem/gems/rufus-scheduler-3.5.2/lib/rufus/scheduler/jobs.rb:218:in do_call' \ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler / jobs.rb: 262: в trigger_now'\", \"/Users/tomburnell/.gem/gems/rufus-scheduler-3.5.2/lib/rufus/scheduler/jobs.rb:307:in блоке (3 уровня) в start_work_thread '\ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler / jobs.rb: 310: в block (2 levels) in start_work_thread'\", \"/Users/tomburnell/.gem/gems/rufus-scheduler-3.5.2/lib/rufus/scheduler/jobs.rb:296:in loop '\ ", \" / Users / tomburnell / .gem / gems / rufus-scheduler-3.5.2 / lib / rufus / scheduler/jobs.rb:296:in `block in start_work_thread '\"] ", 70196180003060] 

    logger[:result] = lambda do |type, passed, opts|
      $logger_mutex.synchronize do
        puts "LOGGING RESULT " + Thread.current.object_id.to_s         # line 209
        log_event "METRIC ns=hc.check type=#{type} result=#{passed ? 'ok':'fail'} key=#{key.join('/').to_json} #{opts.map{|k,v|"#{k}=#{safe_to_json(v)}" if k and v}.compact.join(' ')}"
        $last_result = passed;
        puts "POST LOGGING RESULT " + Thread.current.object_id.to_s
      end
    end

thread # 92, причина остановки = сигнал SIGSTOP frame # 0: 0x00007fff68cb8a16 libsystem_kernel.dylib __psynch_cvwait + 10 frame #1: 0x00007fff68e81589 libsystem_pthread.dylib _pthread_cond_wait + 732 frame # 2: 0x000000010e3bb179 libruby.2.6.dylib gvl_acquire_common [inlined] native_cond_timedwait(cond=<unavailable>, mutex=<unavailable>) at thread_pthread.c:529 frame #3: 0x000000010e3bb13a libruby.2.6.dylib gvl_acquire_common [встроенный].dylib gvl_acquire_common(vm=0x00007fdcbb801c00, th=0x00007fdcc0e1b8e0) at thread_pthread.c:253 frame #5: 0x000000010e3b2ed1 libruby.2.6.dylib blocking_region_end [встроенный] gvl_acquire (vm = 0x00007fdcbb801c00, th =) в thread_pthread.c: 282frame # 6: 0x000000010e3b2eb5 libruby.2.6.dylib blocking_region_end(th=0x00007fdcc0e1b8e0, region=0x000070000b8f34b0) at thread.c:1415 frame #7: 0x000000010e3b2a70 libruby.2.6.dylib rb_thread_io_blocking_region (func = (libruby.2.6.dylib internal_writev_func at io.c:1025), data1=0x000070000b8f3688, fd=<unavailable>) at thread.c:1566 frame #8: 0x000000010e2a927f libruby.2.6.dylib io_fwritev [встроенный] rb_writev_internal (fd =, iov =, iovc = 9): iovcnt =): 0x000000010e2a9264 libruby.2.6.dylib io_fwritev [inlined] io_binwritev(iov=<unavailable>, iovcnt=<unavailable>, fptr=<unavailable>) at io.c:1614 frame #10: 0x000000010e2a8fef libruby.2.6.dylib io_fwritev (argc =, argv =, fptr = 0x00007fdcbb531370) в io.c: 1678 фрейм № 11: 0x000000010e299de5 libruby.2.6013: 0x000000010e3f41f7 libruby.2.6.dylib vm_call0_body [inlined] vm_call0_cfunc(ec=0x00007fdcc0e4c668, argv=0x000070000b8f38c0) at vm_eval.c:100 frame #14: 0x000000010e3f41f7 libruby.2.6.dylib vm_call0_body (ec = 0x00007fdcc0e4c668, вызов =, ci =, cc =, argv = 0x000070000b8f38c0) в vm_eval.c:[inlined] rb_call0 (ec = 0x00007fdcc0e4c668, recv = 140586015886600, mid = 8481, argc = 2, argv =, scope = CALL_FCALL, self = 140586015886600) в vm_eval.c: 308 кадра # 17: 0B0.60000600* rb_funcallv (recv = 140586015886600, mid = 8481, argc = 2, argv =) в vm_eval.c: 823 кадра # 19: 0x000000010e299813 libruby.2.6.dylib rb_io_puts(argc=<unavailable>, argv=0x0000000116750320, out=<unavailable>) at io.c:7756 frame #20: 0x000000010e3f42cc libruby.2.6.dylib vm_call0_body в vm_eval010: 0 фаворита 0: 0 0 0 0 0 0 0 0 0 6 0 0 6 6 0 6 6 6 6 8 6 0 6 6 8 8 8 0 8 0 0 0 8 0 0 0 6 0 0 0 6 0 0 6 6 0 в фбайт для фреймбайтов: 0: 0 0 0 0 0 0 0 0 6 0 0 6 0 0 6 0 0 6 0 0 6 0 0 6 0 0 0 0 0 0 0 6 6 0 ф в ф в фб фб: 0: 0 0 0 0 0 0 0 0 0 6 0 0 0 6 0 0 ф .: ф в ф 0 фб: 0: 0 0 0 0 0 0 0 0 0 0 0 6 0 0 0 0 0 6 0 0 0 0 ф ф ф ф ф ф 0 0 0 0 0 0 в фБ в фрейме: v3_f_f: f0: f0: f0: f0: факс: 0.2.6.dylib vm_call0_body [inlined] vm_call0_cfunc(ec=0x00007fdcc0e4c668, argv=0x0000000116750320) at vm_eval.c:100 frame #22: 0x000000010e3f41f7 libruby.2.6.dylib vm_call0_body (ec = 0x00007fdcc0e4c668, вызов =, ci =, cc =, argv = 0x0000000116750320) в vm_eval.c: 131 кадр # 23: 0x000000010e3f2740 libruby.2.6.dylib * 10 *0x00007fdcc0e4c668, recv = 140586015886600, mid = 16017, argc = 1, argv =, scope = CALL_FCALL, self = 140586015886600) в vm_eval.c: 308 кадровmid = 16017, argc = 1, argv =) в vm_eval.c: 823 кадр # 27: 0x000000010e403311 libruby.2.6.dylib vm_call_cfunc [inlined] vm_call_cfunc_with_frame(ec=<unavailable>, reg_cfp=<unavailable>, ci=0x00007fdcbb56b0c0) at vm_insnhelper.c:1908 frame #28: 0x000000010e403224 libruby.2.6.dylib vm_call_cfunc (ec =, reg_cfp =, вызов =, ci = 0x00007fdcbbmin0) 0.c: 1924 кадр № 29: 0x000000010e3e9adf libruby.2.6.dylib vm_exec_core(ec=<unavailable>, initial=<unavailable>) at insns.def:763 frame #30: 0x000000010e3fdd8e libruby.2.6.dylib rb_vm_exec (ec = 0x00007fdcc0e4c668, mjit_enable_p =) в vm.c: 0 кадр # 31: 0x000000010e3f6b_f_f_t_t_tb.c: 1155

...