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.

Sign up for GitHub

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

Jump to bottom

CI: Fails with "Errno::EACCES: Permission denied - bind(2)" on Windows #4674

Open
Watson1978 opened this issue Oct 18, 2024 · 2 comments · May be fixed by #4675
Open

CI: Fails with "Errno::EACCES: Permission denied - bind(2)" on Windows #4674

Watson1978 opened this issue Oct 18, 2024 · 2 comments · May be fixed by #4675
Assignees
@Watson1978
Labels
bug Something isn't working

Comments

@Watson1978
Copy link
Contributor

Watson1978 commented Oct 18, 2024 •
edited
Loading

Describe the bug

Sometimes, CI fails with "Errno::EACCES: Permission denied - bind(2)" on Windows platform, like

 1) Error: test: skip_invalid_event[tcp](ForwardInputTest::packed forward): Errno::EACCES: Permission denied - bind(2) for 127.0.0.1:53297
C:/hostedtoolcache/windows/Ruby/3.1.6/x64/lib/ruby/3.1.0/socket.rb:179:in `bind'
C:/hostedtoolcache/windows/Ruby/3.1.6/x64/lib/ruby/3.1.0/socket.rb:179:in `bind'
D:/a/fluentd/fluentd/lib/fluent/plugin_helper/server.rb:390:in `server_create_udp_socket'
D:/a/fluentd/fluentd/lib/fluent/plugin_helper/server.rb:174:in `server_create'
D:/a/fluentd/fluentd/lib/fluent/plugin/in_forward.rb:183:in `start'
D:/a/fluentd/fluentd/lib/fluent/test/driver/base.rb:120:in `instance_start'
D:/a/fluentd/fluentd/lib/fluent/test/driver/base.rb:78:in `run'
D:/a/fluentd/fluentd/lib/fluent/test/driver/base_owner.rb:130:in `run'
D:/a/fluentd/fluentd/test/plugin/test_in_forward.rb:491:in `block (2 levels) in <class:ForwardInputTest>'



28) Error: test: Create new connection per send_data(ForwardOutputTest): Errno::EACCES: Permission denied - bind(2) for 127.0.0.1:53356
C:/hostedtoolcache/windows/Ruby/3.1.6/x64/lib/ruby/3.1.0/socket.rb:179:in `bind'
C:/hostedtoolcache/windows/Ruby/3.1.6/x64/lib/ruby/3.1.0/socket.rb:179:in `bind'
D:/a/fluentd/fluentd/lib/fluent/plugin_helper/server.rb:390:in `server_create_udp_socket'
D:/a/fluentd/fluentd/lib/fluent/plugin_helper/server.rb:174:in `server_create'
D:/a/fluentd/fluentd/lib/fluent/plugin/in_forward.rb:183:in `start'
D:/a/fluentd/fluentd/lib/fluent/test/driver/base.rb:120:in `instance_start'
D:/a/fluentd/fluentd/lib/fluent/test/driver/base.rb:78:in `run'
D:/a/fluentd/fluentd/lib/fluent/test/driver/base_owner.rb:130:in `run'
D:/a/fluentd/fluentd/test/plugin/test_out_forward.rb:1260:in `block in <class:ForwardOutputTest>'

To Reproduce

Run Windows platform lane in CI.

Expected behavior

Succeeded without any failures

Your Environment

- Fluentd version:
- Package version:
- Operating system:
- Kernel version:

Your Configuration

none

Your Error Log

none

Additional context

No response
@Watson1978 Watson1978 added waiting-for-triage bug Something isn't working and removed waiting-for-triage labels Oct 18, 2024
@Watson1978 Watson1978 self-assigned this Oct 18, 2024
@Watson1978
Copy link
Contributor Author

Hmm, When I run the test on Windows, it creates a lot of sockets in TIME_WAIT state.
Until the TIME_WAIT state is released, the port in use on that socket is not available.
The tests may be using that port by mistake.

PS C:\src\fluentd> bundle exec rake base_test TEST=test\plugin\test_in_syslog.rb TESTOPTS="-v --no-show-detail-immediately"
test_file_util.rb for non-root user env. Disable this test on root environment
C:/Ruby31-x64/bin/ruby.exe -w -I"lib;test" -Eascii-8bit:ascii-8bit C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/rake-13.2.1/lib/rake/rake_test_loader.rb "test\plugin\test_in_syslog.rb" -v --no-show-detail-immediately
C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/serverengine-2.3.2/lib/serverengine/socket_manager_win.rb:141: warning: assigned but unused variable - type
C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/async-2.17.0/lib/async/task.rb:290: warning: assigned but unused variable - error
C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/async-pool-0.10.1/lib/async/pool/controller.rb:336: warning: assigned but unused variable - error
C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/async-http-0.82.1/lib/async/http/protocol/http1/server.rb:55: warning: assigned but unused variable - error
C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/async-http-0.82.1/lib/async/http/protocol/http2/connection.rb:98: warning: assigned but unused variable - ignored_error
C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/protocol-http-0.41.0/lib/protocol/http/body/stream.rb:233: warning: assigned but unused variable - buffer
C:/src/fluentd/lib/fluent/plugin_helper.rb:46: warning: method redefined; discarding old inherited
C:/src/fluentd/lib/fluent/plugin_helper.rb:46: warning: previous definition of inherited was here
Loaded suite C:/Ruby31-x64/lib/ruby/gems/3.1.0/gems/rake-13.2.1/lib/rake/rake_test_loader
Started
SyslogInputTest:
  test_configure[ipv4]:                                                                                                 .: (0.038125)
  test_configure[ipv6]:                                                                                                 .: (0.002772)
  test_configure_protocol[Use protocol_type]:                                                                           .: (0.002148)
  test_configure_protocol[Use transport]:                                                                               .: (0.001984)
  test_configure_protocol[Use transport and protocol]:                                                                  .: (0.002274)
  test_emit_rfc5452:                                                                                                    .: (1.113086)
  test_emit_unmatched_lines:                                                                                            .: (1.107398)
  test_emit_unmatched_lines_with_address:                                                                               .: (1.117929)
  test_emit_unmatched_lines_with_hostname:                                                                              .: (1.116825)
  test_msg_size:                                                                                                        .: (1.118479)
  test_msg_size_udp_for_large_msg:                                                                                      .: (1.120173)
  test_msg_size_with_facility_key:                                                                                      .: (1.125206)
  test_msg_size_with_include_source_host:                                                                               .: (1.103977)
  test_msg_size_with_json_format:                                                                                       .: (1.119902)
  test_msg_size_with_same_tcp_connection:                                                                               .: (1.121510)
  test_msg_size_with_severity_key[severity_key]:                                                                        .: (1.124568)
  test_msg_size_with_severity_key[priority_key]:                                                                        .: (1.110733)
  test_msg_size_with_source_address_key:                                                                                .: (1.118415)
  test_msg_size_with_source_hostname_key:                                                                               .: (1.117970)
  test_msg_size_with_tcp:                                                                                               .: (1.114958)
  test_respect_protocol_type_than_transport:                                                                            .: (1.118102)
  test_send_keepalive_packet_can_be_enabled:                                                                            .: (0.578499)
  test_send_keepalive_packet_can_not_be_enabled_for_udp:                                                                .: (0.002483)
  test_send_keepalive_packet_is_disabled_by_default:                                                                    .: (0.002141)
  test_time_format[ipv4]:                                                                                               .: (1.111531)
  test_time_format[ipv6]:                                                                                               .: (1.121918)
  octet counting frame:
    test_msg_size_with_same_tcp_connection:                                                                             .: (1.103448)
    test_msg_size_with_tcp:                                                                                             .: (1.107635)
  source_hostname_key and source_address_key features:
    test: resolve_hostname must be true with source_hostname_key:                                                       .: (0.002255)
    test_configure_resolve_hostname[resolve_hostname]:                                                                  .: (0.001720)
    test_configure_resolve_hostname[source_hostname_key]:                                                               .: (0.001566)

Finished in 22.9573934 seconds.
-------------------------------------------------------------------------------------------------------------------------------------------
31 tests, 138 assertions, 0 failures, 0 errors, 0 pendings, 0 omissions, 0 notifications
100% passed
-------------------------------------------------------------------------------------------------------------------------------------------
1.35 tests/s, 6.01 assertions/s

PS C:\src\fluentd> netstat -aon | grep TIME_WAIT
  TCP         127.0.0.1:55680        127.0.0.1:55679        TIME_WAIT       0
  TCP         127.0.0.1:55682        127.0.0.1:55681        TIME_WAIT       0
  TCP         127.0.0.1:55684        127.0.0.1:55683        TIME_WAIT       0
  TCP         127.0.0.1:55697        127.0.0.1:55696        TIME_WAIT       0
  TCP         127.0.0.1:55707        127.0.0.1:55706        TIME_WAIT       0
  TCP         127.0.0.1:55710        127.0.0.1:55709        TIME_WAIT       0
  TCP         127.0.0.1:55718        127.0.0.1:55717        TIME_WAIT       0
  TCP         127.0.0.1:55721        127.0.0.1:55720        TIME_WAIT       0
  TCP         127.0.0.1:55725        127.0.0.1:55724        TIME_WAIT       0
  TCP         127.0.0.1:55728        127.0.0.1:55727        TIME_WAIT       0
  TCP         127.0.0.1:55731        127.0.0.1:55730        TIME_WAIT       0
  TCP         127.0.0.1:55734        127.0.0.1:55733        TIME_WAIT       0
  TCP         127.0.0.1:55737        127.0.0.1:55736        TIME_WAIT       0
  TCP         127.0.0.1:55738        127.0.0.1:55735        TIME_WAIT       0
  TCP         127.0.0.1:55741        127.0.0.1:55740        TIME_WAIT       0
  TCP         127.0.0.1:55745        127.0.0.1:55744        TIME_WAIT       0
  TCP         127.0.0.1:55748        127.0.0.1:55747        TIME_WAIT       0
  TCP         127.0.0.1:55752        127.0.0.1:55751        TIME_WAIT       0
  TCP         127.0.0.1:55755        127.0.0.1:55754        TIME_WAIT       0
  TCP         127.0.0.1:55756        127.0.0.1:55753        TIME_WAIT       0
  TCP         127.0.0.1:55757        127.0.0.1:55753        TIME_WAIT       0
  TCP         127.0.0.1:55763        127.0.0.1:55762        TIME_WAIT       0
  TCP         127.0.0.1:55766        127.0.0.1:55765        TIME_WAIT       0
  TCP         127.0.0.1:55772        127.0.0.1:55771        TIME_WAIT       0
  TCP         127.0.0.1:55776        127.0.0.1:55775        TIME_WAIT       0
  TCP         127.0.0.1:55779        127.0.0.1:55778        TIME_WAIT       0
  TCP         127.0.0.1:55780        127.0.0.1:55777        TIME_WAIT       0
  TCP         127.0.0.1:55786        127.0.0.1:55785        TIME_WAIT       0
  TCP         127.0.0.1:55787        127.0.0.1:55784        TIME_WAIT       0
  TCP         127.0.0.1:55788        127.0.0.1:55784        TIME_WAIT       0
  TCP         192.168.10.13:55610    117.18.232.200:443     TIME_WAIT       0
  TCP         192.168.10.13:55625    52.168.117.175:443     TIME_WAIT       0
  TCP         192.168.10.13:55643    172.65.225.25:443      TIME_WAIT       0
  TCP         192.168.10.13:55698    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55699    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55700    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55702    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55703    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55704    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55711    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55712    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55713    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55758    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55759    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55760    192.168.10.1:53        TIME_WAIT       0
  TCP         192.168.10.13:55781    20.189.173.25:443      TIME_WAIT       0

@Watson1978
Copy link
Contributor Author

The port used in the test is determined by the unused_port method.
However, since the protocols are not properly specified, they wll look at free TCP ports.
https://github.com/search?q=repo%3Afluent%2Ffluentd%20unused_port&type=code

At least, looks for me that it need to specify protocols properly in some cases.

@Watson1978 Watson1978 linked a pull request Oct 20, 2024 that will close this issue
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@Watson1978 Watson1978

Labels
bug Something isn't working
Projects
Fluentd Kanban
Status: Work-In-Progress
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

tests: fix unused_port Watson1978/fluentd
1 participant
@Watson1978