Errno::ECONNRESET: Connection reset by peer
do11 opened this issue · 11 comments
do11 commented
I did simple dns proxy (based on your flakey-dns example), which NXDomain some domains and proxy others. After a while it's crashed with such log message:
E, [2016-05-19T18:36:05.380280 #14018] ERROR -- : Actor crashed!
Errno::ECONNRESET: Connection reset by peer
<internal:prelude>:76:in `__read_nonblock'
<internal:prelude>:76:in `read_nonblock'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:41:in `block in sysread'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:389:in `synchronize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:39:in `sysread'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:128:in `readpartial'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transport.rb:58:in `read_chunk'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:159:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
E, [2016-05-19T18:36:05.380877 #14018] ERROR -- : Actor crashed!
Errno::ECONNRESET: Connection reset by peer
<internal:prelude>:76:in `__read_nonblock'
<internal:prelude>:76:in `read_nonblock'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:41:in `block in sysread'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:389:in `synchronize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:39:in `sysread'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:128:in `readpartial'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transport.rb:58:in `read_chunk'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:159:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
W, [2016-05-19T18:36:05.381014 #14018] WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
E, [2016-05-19T18:36:05.382608 #14018] ERROR -- : Actor crashed!
Errno::ECONNRESET: Connection reset by peer
<internal:prelude>:76:in `__read_nonblock'
<internal:prelude>:76:in `read_nonblock'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:41:in `block in sysread'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:389:in `synchronize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:39:in `sysread'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:128:in `readpartial'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transport.rb:58:in `read_chunk'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:159:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
W, [2016-05-19T18:36:05.383086 #14018] WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
=== Daemon Exception Backtrace @ 2016-05-23 12:56:43 +0300 ===
SignalException: SIGTERM
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/notification.rb:52:in `read'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/notification.rb:52:in `wait'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:134:in `sleep_until_interrupted'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:143:in `run'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:157:in `spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:84:in `block in spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:67:in `fork'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:67:in `spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:113:in `start'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:53:in `daemonize'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:180:in `daemonize'
dns-proxy.rb:50:in `<main>'
=== Daemon Crashed ===
=== Daemon Stopping @ 2016-05-23 12:56:43 +0300 ===
Then daemon remained to be run while dns is not serving (actor is not restarted). Line 50 is match()'s 'end' keyword.
This is obscure. How would you suggest to debug or workaround it? It's possible that uplink dns server temporary returned connection refused, I would like to catch and ignore this exception, but it does not show my script anywhere in stack trace on Errno::ECONNRESET exception.
do11 commented
Even when I simulate crash with raise on third request, and do not using process/daemon, rubydns process is not exiting. How would you suggest to catch errors and fall back?
I want RubyDNS process exit on crash, so I can restart it or catch errors, ignore, and continue to work. But, currently it just crash internally, abort functionality and hang. This is not robust at all...
ioquatix commented
It might be an issue with celluloid, can you provide the working code you have?
do11 commented
More funny crashes:
E, [2016-05-24T22:17:32.710973 #21621] ERROR -- : <1> Exception thrown while processing Resolv::DNS::Resource::IN::NS!
E, [2016-05-24T22:17:32.713109 #21621] ERROR -- : Actor crashed!
Errno::EHOSTUNREACH: No route to host - connect(2) for 1.1.1.1:53
/usr/local/lib/ruby/2.3.0/socket.rb:1207:in `__connect_nonblock'
/usr/local/lib/ruby/2.3.0/socket.rb:1207:in `connect_nonblock'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/tcp_socket.rb:82:in `initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:240:in `new'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:240:in `try_tcp_server'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:199:in `try_server'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:157:in `block (2 levels) in dispatch_request'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid.rb:407:in `block in timeout'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:252:in `timeout'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid.rb:406:in `timeout'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:156:in `block in dispatch_request'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:284:in `block in each'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:281:in `each'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:281:in `each'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:147:in `dispatch_request'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:93:in `query'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:63:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
(celluloid):0:in `remote procedure call'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:92:in `value'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/proxies/sync_proxy.rb:33:in `method_missing'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transaction.rb:109:in `passthrough'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transaction.rb:83:in `passthrough!'
dns-proxy.rb:51:in `block (2 levels) in startup'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:332:in `process'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transaction.rb:192:in `process'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:106:in `block in process_query'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:98:in `each'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:98:in `process_query'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:55:in `process_query'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:161:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
E, [2016-05-24T22:17:32.713181 #21621] ERROR -- : Errno::EHOSTUNREACH: No route to host - connect(2) for 1.1.1.1:53
E, [2016-05-24T22:17:32.714024 #21621] ERROR -- : /usr/local/lib/ruby/2.3.0/socket.rb:1207:in `__connect_nonblock'
E, [2016-05-24T22:17:32.714174 #21621] ERROR -- : /usr/local/lib/ruby/2.3.0/socket.rb:1207:in `connect_nonblock'
E, [2016-05-24T22:17:32.714532 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/tcp_socket.rb:82:in `initialize'
E, [2016-05-24T22:17:32.714638 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:240:in `new'
E, [2016-05-24T22:17:32.714686 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:240:in `try_tcp_server'
E, [2016-05-24T22:17:32.714724 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:199:in `try_server'
E, [2016-05-24T22:17:32.714760 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:157:in `block (2 levels) in dispatch_request'
E, [2016-05-24T22:17:32.714797 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid.rb:407:in `block in timeout'
E, [2016-05-24T22:17:32.714833 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:252:in `timeout'
E, [2016-05-24T22:17:32.714870 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid.rb:406:in `timeout'
E, [2016-05-24T22:17:32.714907 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:156:in `block in dispatch_request'
E, [2016-05-24T22:17:32.714943 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:284:in `block in each'
E, [2016-05-24T22:17:32.714979 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:281:in `each'
E, [2016-05-24T22:17:32.715016 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:281:in `each'
E, [2016-05-24T22:17:32.715051 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:147:in `dispatch_request'
E, [2016-05-24T22:17:32.715088 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/resolver.rb:93:in `query'
E, [2016-05-24T22:17:32.715152 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
E, [2016-05-24T22:17:32.715190 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
E, [2016-05-24T22:17:32.715226 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:63:in `dispatch'
E, [2016-05-24T22:17:32.715262 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
E, [2016-05-24T22:17:32.715298 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
E, [2016-05-24T22:17:32.715334 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
E, [2016-05-24T22:17:32.715370 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
E, [2016-05-24T22:17:32.715450 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
E, [2016-05-24T22:17:32.715487 #21621] ERROR -- : (celluloid):0:in `remote procedure call'
E, [2016-05-24T22:17:32.715522 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:92:in `value'
E, [2016-05-24T22:17:32.715558 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/proxies/sync_proxy.rb:33:in `method_missing'
E, [2016-05-24T22:17:32.715595 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transaction.rb:109:in `passthrough'
E, [2016-05-24T22:17:32.715632 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transaction.rb:83:in `passthrough!'
E, [2016-05-24T22:17:32.715674 #21621] ERROR -- : dns-proxy.rb:51:in `block (2 levels) in startup'
E, [2016-05-24T22:17:32.715709 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:332:in `process'
E, [2016-05-24T22:17:32.715745 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transaction.rb:192:in `process'
E, [2016-05-24T22:17:32.715781 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:106:in `block in process_query'
E, [2016-05-24T22:17:32.715817 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:98:in `each'
E, [2016-05-24T22:17:32.715852 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/server.rb:98:in `process_query'
E, [2016-05-24T22:17:32.715888 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:55:in `process_query'
E, [2016-05-24T22:17:32.715924 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:161:in `handle_connection'
E, [2016-05-24T22:17:32.715960 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
E, [2016-05-24T22:17:32.715995 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
E, [2016-05-24T22:17:32.716031 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
E, [2016-05-24T22:17:32.716067 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
E, [2016-05-24T22:17:32.716104 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
E, [2016-05-24T22:17:32.716141 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
E, [2016-05-24T22:17:32.716178 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
E, [2016-05-24T22:17:32.716214 #21621] ERROR -- : /usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
D, [2016-05-24T22:17:32.716291 #21621] DEBUG -- : <1> Time to process request: 8.01308856s
E, [2016-05-24T22:17:32.716781 #21621] ERROR -- : Actor crashed!
Errno::EPIPE: Broken pipe
<internal:prelude>:134:in `__write_nonblock'
<internal:prelude>:134:in `write_nonblock'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:61:in `block in syswrite'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:389:in `synchronize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:58:in `syswrite'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:355:in `do_write'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-io-0.16.2/lib/celluloid/io/stream.rb:249:in `write'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transport.rb:70:in `write_chunk'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/transport.rb:65:in `write_message'
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:163:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
W, [2016-05-24T22:17:32.717014 #21621] WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
D, [2016-05-24T22:17:39.691524 #21621] DEBUG -- : <> Receiving incoming query (36 bytes) to RubyDNS::UDPHandler...
D, [2016-05-24T22:17:39.691829 #21621] DEBUG -- : <33748> Processing question redacted Resolv::DNS::Resource::IN::A...
D, [2016-05-24T22:17:39.691897 #21621] DEBUG -- : <33748> Searching for redacted Resolv::DNS::Resource::IN::A
D, [2016-05-24T22:17:39.691953 #21621] DEBUG -- : <33748> Checking rule [//]...
D, [2016-05-24T22:17:39.692027 #21621] DEBUG -- : <33748> Regexp pattern matched with #<MatchData "">.
D, [2016-05-24T22:17:39.695048 #21621] DEBUG -- : [19454] Sending request [[#<Resolv::DNS::Name: redacted.>, Resolv::DNS::Resource::IN::A]] to server [:udp, "1.1.1.1", 53]
=== Daemon Exception Backtrace @ 2016-05-24 22:17:40 +0300 ===
SignalException: SIGTERM
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/notification.rb:52:in `read'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/notification.rb:52:in `wait'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:134:in `sleep_until_interrupted'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:143:in `run'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:157:in `spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:84:in `block in spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:67:in `fork'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:67:in `spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:113:in `start'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:53:in `daemonize'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:180:in `daemonize'
dns-proxy.rb:57:in `<main>'
=== Daemon Crashed ===
=== Daemon Stopping @ 2016-05-24 22:17:40 +0300 ===
D, [2016-05-24T22:17:40.239006 #21621] DEBUG -- : Terminating 3 actors...
W, [2016-05-24T22:17:40.239973 #21621] WARN -- : Terminating task: type=:call, meta={:method_name=>:query}, status=:iowait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
W, [2016-05-24T22:17:40.240140 #21621] WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
W, [2016-05-24T22:17:40.240554 #21621] WARN -- : Terminating task: type=:call, meta={:method_name=>:respond}, status=:callwait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
=== Log Marked @ 2016-05-24 22:17:40 +0300 [20072] ===
I redacted hostname and IP. Obviously cause is not in hostnames, but in temporary network problem, EHOSTUNREACH.
do11 commented
Just a few minutes later another crash:
D, [2016-05-24T23:06:43.460556 #20200] DEBUG -- : <> Receiving incoming query (17 bytes) to RubyDNS::TCPHandler...
D, [2016-05-24T23:06:43.460810 #20200] DEBUG -- : <1> Processing question Resolv::DNS::Resource::IN::NS...
D, [2016-05-24T23:06:43.460884 #20200] DEBUG -- : <1> Searching for Resolv::DNS::Resource::IN::NS
D, [2016-05-24T23:06:43.460939 #20200] DEBUG -- : <1> Checking rule [//]...
D, [2016-05-24T23:06:43.460998 #20200] DEBUG -- : <1> Regexp pattern matched with #<MatchData "">.
D, [2016-05-24T23:06:43.461954 #20200] DEBUG -- : [29927] Sending request [[#<Resolv::DNS::Name: .>, Resolv::DNS::Resource::IN::NS]] to server [:udp, "1.1.1.1
2", 53]
D, [2016-05-24T23:06:43.464306 #20200] DEBUG -- : [29927] Received valid response with 13 answer(s).
D, [2016-05-24T23:06:43.464493 #20200] DEBUG -- : <1> Time to process request: 0.00369995s
D, [2016-05-24T23:06:43.465304 #20200] DEBUG -- : <1> Wrote 320 bytes via TCP...
E, [2016-05-24T23:06:50.453277 #20200] ERROR -- : Actor crashed!
Errno::ENOTCONN: Transport endpoint is not connected - getpeername(2)
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:156:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
E, [2016-05-24T23:06:50.453917 #20200] ERROR -- : Actor crashed!
Errno::ENOTCONN: Transport endpoint is not connected - getpeername(2)
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:156:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
W, [2016-05-24T23:06:50.454077 #20200] WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
E, [2016-05-24T23:06:50.455385 #20200] ERROR -- : Actor crashed!
Errno::ENOTCONN: Transport endpoint is not connected - getpeername(2)
/usr/local/lib/ruby/gems/2.3.0/gems/rubydns-1.0.3/lib/rubydns/handler.rb:156:in `handle_connection'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/usr/local/lib/ruby/gems/2.3.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
W, [2016-05-24T23:06:50.456422 #20200] WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
Celluloid::TaskFiber backtrace unavailable. Please try `Celluloid.task_class = Celluloid::TaskThread` if you need backtraces here.
=== Daemon Exception Backtrace @ 2016-05-24 23:07:59 +0300 ===
SignalException: SIGTERM
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/notification.rb:52:in `read'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/notification.rb:52:in `wait'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:134:in `sleep_until_interrupted'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:143:in `run'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:157:in `spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:84:in `block in spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:67:in `fork'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:67:in `spawn'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:113:in `start'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon/controller.rb:53:in `daemonize'
/usr/local/lib/ruby/gems/2.3.0/gems/process-daemon-1.0.1/lib/process/daemon.rb:180:in `daemonize'
dns-proxy.rb:57:in `<main>'
=== Daemon Crashed ===
=== Daemon Stopping @ 2016-05-24 23:07:59 +0300 ===
D, [2016-05-24T23:07:59.026732 #20200] DEBUG -- : Terminating 4 actors...
=== Log Marked @ 2016-05-24 23:07:59 +0300 [1390] ===
do11 commented
Yes, maybe root of problem is in celluloid, but it's rubydns who is being non-robust. Code: https://gist.github.com/do11/5a57bd9d682c02f711db5d692682174d
ioquatix commented
Unfortunately in this case I think you are wrong. But I will review it when I have time :)
do11 commented
Wrong in what sense? I code in rubydns and daemon crashes and I can not catch exception (as you can see, my code is not even in backtrace), and it not fully exits (to be restarted via daemons). Only way, currently, to run rubynds server is to monitor it with monit and restart if it stops to answer dns requests.
ioquatix commented
Sorry, dude, I'm doing my best to resolve this, but this isn't a bug in RubyDNS but issue within Celluloid. I understand as an end user you don't really need to know the distinction, but it's not something I can just fix because I don't have full control over celluloid :( I'm working on it but I have to prioritise paid work.
do11 commented
Ok ok, I'm not pushing over your capabilities. Just good you are not abandoning it.
-side rant-
it seems that dynamic/typeless nature of ruby, maybe doing good with duck typing, but playing nasty with exceptions - because, exceptions are rarely documented, and not obliged to be catched (unlike java). Thus, there is always chance of unexpected exception, and exceptions are fatal. I'm convinced that's very hard to write robust program in ruby. Also, inviting object-orientedness of ruby, cause people to naively create bad OOP design (because good OOP design is actually harder than people except). Also, ruby charset encoding caveats. This all make a lot of modules unexpectedly unusable.
ioquatix commented
@do11 There is a new 2.0.0.pre.rc1 which no longer uses celluloid. Can you please try it out? Thanks so much for your time and patience.
ioquatix commented
Let me know if you have any further issues, and I'd love to have feedback about the 2.0 release! Thanks :)