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

fluentd fails for missing unix domain socket #561

Open
eyberg opened this issue Feb 27, 2019 · 9 comments
Open

fluentd fails for missing unix domain socket #561

eyberg opened this issue Feb 27, 2019 · 9 comments

Comments

@eyberg
Copy link
Contributor

eyberg commented Feb 27, 2019

this is one of those toss-ups on whether or not we want to support this - i haven't delved into the code yet but if it's a case where it spawns a bunch of processes and then uses this to communicate between them that's obviously not a usecase but I don't actually know if that's the case or not

as you can see there is a mention of a 'supervisor' and ruby doesn't have real threads so this might actually be that case - needs some further investigation

2019-02-27 19:33:21 +0000 [info]: fluent/log.rb:322:info: starting fluentd-1.4.0 pid=1 ruby="2.3.1"
2019-02-27 19:33:21 +0000 [info]: fluent/log.rb:322:info: spawn command to main:  cmdline=["/usr/bin/ruby2.3", "-Eascii-8bit:ascii-8bit", "/.gem/ruby/2.3.0/bin/fluentd", "-c", "/fluent/fluent.conf", "-vv", "--under-supervisor"]
Unexpected error Address family not supported by protocol - socket(2) for /tmp/SERVERENGINE_SOCKETMANAGER_2019-02-27T19:33:21Z_1
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:75:in `initialize'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:75:in `new'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:75:in `start_server'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:94:in `initialize'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:87:in `new'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:87:in `open'
  /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:65:in `before_run'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/server.rb:125:in `main'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/daemon.rb:119:in `main'
  /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/daemon.rb:68:in `run'
  /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:632:in `supervise'
  /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:502:in `run_supervisor'
  /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/command/fluentd.rb:310:in `<top (required)>'
  /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  /.gem/ruby/2.3.0/gems/fluentd-1.4.0/bin/fluentd:8:in `<top (required)>'
  /.gem/ruby/2.3.0/bin/fluentd:23:in `load'
  /.gem/ruby/2.3.0/bin/fluentd:23:in `<main>'
exit_group
exit status 1
eyberg@dungeon:~/fl$ cat config.json
{
  "Args": ["/.gem/ruby/2.3.0/bin/fluentd", "-c", "/fluent/fluent.conf", "-vv"],
  "Dirs": ["fluent"],
  "Files": ["/lib/x86_64-linux-gnu/librt.so.1", "/lib/x86_64-linux-gnu/libz.so.1", "/lib/x86_64-linux-gnu/libssl.so.1.0.0", "/lib/x86_64-linux-gnu/libcrypto.so.1.0.0"],
  "MapDirs": {"/home/eyberg/.gem/*": "/.gem" }
}

install instructions taken from

https://docs.fluentd.org/v1.0/articles/install-by-gem

for implementation/test case:

https://github.com/troydhanson/network/blob/master/unixdomain/01.basic/cli.c
https://github.com/troydhanson/network/blob/master/unixdomain/01.basic/srv.c
http://man7.org/linux/man-pages/man7/unix.7.html

@eyberg
Copy link
Contributor Author

eyberg commented Feb 27, 2019

just playing around -- without supervisor =>

[ruby /.gem/ruby/2.3.0/bin/fluentd -c /fluent/fluent.conf -vv --no-supervisor]
booting /home/eyberg/.ops/images/ruby_2.3.1/ruby.img ...
warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
assigned: 10.0.2.15
2019-02-27 19:43:08 +0000 [info]: fluent/log.rb:322:info: starting fluentd-1.4.0 without supervision pid=1 ruby="2.3.1"
2019-02-27 19:43:08 +0000 [error]: fluent/log.rb:362:error: unexpected error error_class=Errno::EAFNOSUPPORT error="Address family not supported by protocol - socket(2) for /tmp/SERVERENGINE_SOCKETMANAGER_2019-02-27T19:43:08Z_1"

but 'under supervisor' we get something that gets a further along

@eyberg
Copy link
Contributor Author

eyberg commented May 29, 2019

get a further along now ->

eyberg@dungeon:~/fl$ ops load ruby_2.3.1  -c config.json
[ruby /.gem/ruby/2.3.0/bin/fluentd -c /fluent/fluent.conf -vv --under-supervisor]
booting /home/eyberg/.ops/images/ruby.img ...
qemu-system-x86_64: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
assigned: 10.0.2.15
2019-05-29 21:16:21 +0000 [info]: fluent/log.rb:322:info: gem 'fluentd' version '1.4.0'
2019-05-29 21:16:21 +0000 [info]: fluent/log.rb:322:info: adding match pattern="debug.**" type="stdout"
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered output plugin 'stdout'
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered buffer plugin 'memory'
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered formatter plugin 'stdout'
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered formatter plugin 'json'
2019-05-29 21:16:21 +0000 [info]: fluent/log.rb:322:info: adding match pattern="system.**" type="forward"
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered output plugin 'forward'
2019-05-29 21:16:21 +0000 [info]: #0 fluent/log.rb:322:info: adding forwarding server '192.168.0.12:24224' host="192.168.0.12" port=24224 weight=60 plugin_id="object:ab08ec"
2019-05-29 21:16:21 +0000 [info]: #0 [forward_output] adding forwarding server '192.168.0.11:24224' host="192.168.0.11" port=24224 weight=60 plugin_id="forward_output"
2019-05-29 21:16:21 +0000 [info]: fluent/log.rb:322:info: adding source type="forward"
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered input plugin 'forward'
2019-05-29 21:16:21 +0000 [info]: fluent/log.rb:322:info: adding source type="http"
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered parser plugin 'in_http'
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered input plugin 'http'
2019-05-29 21:16:21 +0000 [trace]: #0 fluent/log.rb:281:trace: registered parser plugin 'msgpack'
2019-05-29 21:16:22 +0000 [trace]: #0 fluent/log.rb:281:trace: registered parser plugin 'json'
2019-05-29 21:16:22 +0000 [info]: #0 [http_input] Oj is not installed, and failing back to Yajl for json parser
2019-05-29 21:16:22 +0000 [info]: fluent/log.rb:322:info: adding source type="monitor_agent"
2019-05-29 21:16:22 +0000 [trace]: #0 fluent/log.rb:281:trace: registered input plugin 'monitor_agent'
2019-05-29 21:16:22 +0000 [info]: fluent/log.rb:322:info: adding source type="debug_agent"
2019-05-29 21:16:22 +0000 [trace]: #0 fluent/log.rb:281:trace: registered input plugin 'debug_agent'
2019-05-29 21:16:22 +0000 [info]: #0 fluent/log.rb:322:info: starting fluentd worker pid=1 ppid=-38 worker=0
2019-05-29 21:16:22 +0000 [debug]: #0 [forward_output] buffer started instance=11262240 stage_size=0 queue_size=0
2019-05-29 21:16:22 +0000 [info]: #0 fluent/log.rb:322:info: delayed_commit_timeout is overwritten by ack_response_timeout
2019-05-29 21:16:22 +0000 [debug]: #0 fluent/log.rb:302:debug: rebuilding weight array lost_weight=0
2019-05-29 21:16:22 +0000 [info]: #0 [forward_output] delayed_commit_timeout is overwritten by ack_response_timeout
2019-05-29 21:16:22 +0000 [debug]: #0 [forward_output] rebuilding weight array lost_weight=0
2019-05-29 21:16:22 +0000 [info]: #0 [debug_agent_input] listening dRuby uri="druby://127.0.0.1:24230" object="Fluent::Engine" worker=0
2019-05-29 21:16:22 +0000 [debug]: #0 [monitor_agent_input] listening monitoring http server on http://0.0.0.0:24220/api/plugins for worker0
2019-05-29 21:16:22 +0000 [debug]: #0 [http_input] listening http bind="0.0.0.0" port=8888
2019-05-29 21:16:22 +0000 [error]: #0 fluent/log.rb:362:error: unexpected error error_class=TypeError error="no implicit conversion of nil into String"
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:27:in `initialize'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:27:in `new'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:27:in `connect_peer'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:49:in `listen'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:64:in `listen_tcp'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/plugin/in_http.rb:138:in `start'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:203:in `block in start'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:192:in `block (2 levels) in lifecycle'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:191:in `each'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:191:in `block in lifecycle'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:178:in `each'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:178:in `lifecycle'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:202:in `start'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/engine.rb:274:in `start'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/engine.rb:219:in `run'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:799:in `run_engine'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:549:in `block in run_worker'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:724:in `main_process'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:544:in `run_worker'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/command/fluentd.rb:316:in `<top (required)>'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/bin/fluentd:8:in `<top (required)>'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/bin/fluentd:23:in `load'
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/bin/fluentd:23:in `<main>'
2019-05-29 21:16:22 +0000 [error]: #0 fluent/log.rb:362:error: unexpected error error_class=TypeError error="no implicit conversion of nil into String"
  2019-05-29 21:16:22 +0000 [error]: #0 fluent/supervisor.rb:723:main_process: suppressed same stacktrace
exit status 3

it seems like this is supposed to have a number of worker processes but i read that it can be configured as single process as well, also https://fluentbit.io/ looks to be written in pure c

@eyberg
Copy link
Contributor Author

eyberg commented May 29, 2019

when running w/ '--no-supervisor' option which (i'm hoping sets it to single worker process) we get this

eyberg@dungeon:~/fl$  ops load ruby_2.3.1  -c config.json
[ruby /.gem/ruby/2.3.0/bin/fluentd -c /fluent/fluent.conf -vv --no-supervisor]
booting /home/eyberg/.ops/images/ruby.img ...
qemu-system-x86_64: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
assigned: 10.0.2.15
2019-05-29 21:37:02 +0000 [info]: fluent/log.rb:322:info: starting fluentd-1.4.0 without supervision pid=1 ruby="2.3.1"
2019-05-29 21:37:02 +0000 [error]: fluent/log.rb:362:error: unexpected error error_class=Errno::EAFNOSUPPORT error="Address family not supported by protocol - socket(2) for /tmp/SERVERENGINE_SOCKETMANAGER_2019-05-29T21:37:02Z_1"
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:75:in `initialize'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:75:in `new'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:75:in `start_server'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:94:in `initialize'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:87:in `new'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:87:in `open'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:559:in `create_socket_manager'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:545:in `block in run_worker'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:724:in `main_process'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:544:in `run_worker'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/command/fluentd.rb:316:in `<top (required)>'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/bin/fluentd:8:in `<top (required)>'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/bin/fluentd:23:in `load'
  2019-05-29 21:37:02 +0000 [error]: fluent/supervisor.rb:723:main_process: /.gem/ruby/2.3.0/bin/fluentd:23:in `<main>'
exit status 3
eyberg@dungeon:~/fl$ cat config.json
{
  "Args": ["/.gem/ruby/2.3.0/bin/fluentd", "-c", "/fluent/fluent.conf", "-vv", "--no-supervisor"],
  "Dirs": ["fluent"],
  "Files": ["/lib/x86_64-linux-gnu/librt.so.1", "/lib/x86_64-linux-gnu/libz.so.1", "/usr/lib/x86_64-linux-gnu/libssl.so.1.0.0", "/usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0"],
  "MapDirs": {"/home/eyberg/.gem/*": "/.gem" }
}
2019-05-29 21:40:05 +0000 [info]: fluent/log.rb:322:info: starting fluentd-1.4.0 without supervision pid=1 ruby="2.3.1"
1 direct return: 120, rsp 0x785fdef0
1 clock_gettime
1 clock_gettime: clk_id 0
1 direct return: 0, rsp 0x785fd5d8
1 open
1 open: "/etc/localtime", flags 80000, mode 1b6
1 "/etc/localtime" - not found
1 direct return: -2, rsp 0x785fd500
1 umask
1 nosyscall umask
1 socket
1 direct return: -97, rsp 0x785fcc58
1 umask
1 nosyscall umask
1 clock_gettime
1 clock_gettime: clk_id 0
1 direct return: 0, rsp 0x785fdfe8
1 open
1 open: "/etc/localtime", flags 80000, mode 1b6
1 "/etc/localtime" - not found
1 direct return: -2, rsp 0x785fd2d0
1 write
2019-05-29 21:40:05 +0000 [error]: fluent/log.rb:362:error: unexpected error error_class=Errno::EAFNOSUPPORT error="Address family not supported by protocol - socket(2) for /tmp/SERVERENGINE_SOCKETMANAGER_2019-05-29T21:40:05Z_1"

https://ruby-doc.org/stdlib-2.3.0/libdoc/socket/rdoc/UNIXServer.html
https://github.com/ruby/ruby/blob/d48783bb0236db505fe1205d1d9822309de53a36/ext/socket/unixsocket.c#L68

@eyberg
Copy link
Contributor Author

eyberg commented May 29, 2019

this is again one of those cases where ipc doesn't make a ton of sense but if we can accomodate existing software that'll go a ways

eyberg@dungeon:~/tr$ ops load ruby_2.3.1 -a hi.rb
[ruby hi.rb]
booting /home/eyberg/.ops/images/ruby.img ...
qemu-system-x86_64: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
assigned: 10.0.2.15
hi.rb:3:in `initialize': Address family not supported by protocol - socket(2) for /tmp/sock (Errno::EAFNOSUPPORT)
        from hi.rb:3:in `open'
        from hi.rb:3:in `<main>'
exit status 3
eyberg@dungeon:~/tr$ cat hi.rb
require 'socket'

UNIXServer.open("/tmp/sock") {|serv|
  UNIXSocket.open("/tmp/sock") {|c|
    s = serv.accept
    s.puts "hi"
    s.close
    p c.read #=> "hi\n"
  }
}

if (domain != AF_INET) {

@eyberg
Copy link
Contributor Author

eyberg commented May 29, 2019

@eyberg
Copy link
Contributor Author

eyberg commented Mar 31, 2020

w/ up to #1100 ->

2020-03-31 21:56:24 +0000 [error]: fluent/log.rb:362:error: unexpected error error_class=Errno::ENOTCONN error="Transport endpoint is not connected - recvmsg(2)"
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:37:in `recv_io'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager_unix.rb:37:in `recv'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:56:in `listen'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/serverengine-2.1.0/lib/serverengine/socket_manager.rb:64:in `listen_tcp'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/plugin/in_http.rb:138:in `start'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:203:in `block in start'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:192:in `block (2 levels) in lifecycle'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:191:in `each'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:191:in `block in lifecycle'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:178:in `each'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:178:in `lifecycle'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/root_agent.rb:202:in `start'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/engine.rb:274:in `start'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/engine.rb:219:in `run'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:801:in `run_engine'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:549:in `block in run_worker'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:726:in `main_process'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/supervisor.rb:544:in `run_worker'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/lib/fluent/command/fluentd.rb:316:in `<top (required)>'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/gems/fluentd-1.4.0/bin/fluentd:8:in `<top (required)>'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/bin/fluentd:23:in `load'
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:549:block in run_worker: /.gem/ruby/2.3.0/bin/fluentd:23:in `<main>'
2020-03-31 21:56:24 +0000 [error]: fluent/log.rb:362:error: unexpected error error_class=Errno::ENOTCONN error="Transport endpoint is not connected - recvmsg(2)"
  2020-03-31 21:56:24 +0000 [error]: fluent/supervisor.rb:725:main_process: suppressed same stacktrace

@francescolavra
Copy link
Member

With #1248, it gets past the recvmsg() error, but then fails with /usr/local/lib/ruby/gems/2.7.0/gems/serverengine-2.2.1/lib/serverengine/socket_manager_unix.rb:37: [BUG] rsock_detect_cloexec: fcntl(-1, F_GETFD) failed: Bad file descriptor. The reason for this failure is that fluentd uses the send_io() and recv_io() methods of the UNIXSocket class (https://www.rubydoc.info/stdlib/socket/2.2.2/UNIXSocket), which internally use sendmsg() and recvmsg() to transfer ancillary data, which we don't support; more specifically, those methods transfer data of type SCM_RIGHTS, which is used to send or receive a set of open file descriptors (see man 7 unix). The usage of SCM_RIGHTS ancillary data is mostly relevant in inter-process communication, but fluentd uses it even within a single process.

@francescolavra francescolavra removed their assignment Dec 8, 2021
@francescolavra
Copy link
Member

#1692

@eyberg
Copy link
Contributor Author

eyberg commented Jun 4, 2022

nanovms/ops#1339

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