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

Introspection fails when called multiple times in threads #73

Open
zaburt opened this issue Feb 23, 2018 · 3 comments
Open

Introspection fails when called multiple times in threads #73

zaburt opened this issue Feb 23, 2018 · 3 comments

Comments

@zaburt
Copy link

zaburt commented Feb 23, 2018

I am trying to build a Rails application that regularly checks network status, Systemd service status etc. showing them on the UI. I need to use Puma which works with threads. When the application makes calls to DBus we start getting DBus::InvalidPacketException over and over during introspection. I am not sure if it is because of using threads, or if threads just makes it easier to reproduce (ex. calling DBus too fast).

I see it happen on OpenSUSE 42.3 and Ubuntu 16.04. Happens with Ruby 2.4.3 and 2.3.6, did not try other Ruby versions. This is reproducable with 2 threads too. Systemd is just an example, issue happens when calling NetworkManager too.

require 'dbus'

PARALLEL = 5
UNIT_NAME = 'ruby_dbus_test.service'

def local_service_unit_is_active(k)
  puts "current thread #{Thread.current[:num]}\n"
  sys_bus = DBus.system_bus
  core_service = sys_bus.service('org.freedesktop.systemd1')
  obj = core_service.object('/org/freedesktop/systemd1')
  obj.default_iface = 'org.freedesktop.systemd1'

  puts "before obj.introspect #{Thread.current[:num]}\n"
  obj.introspect
  puts "after obj.introspect #{Thread.current[:num]}\n"
  obj
end

def build_thread(k)
  Thread.new do
    Thread.current.abort_on_exception = true
    Thread.current[:num] = k

    resp = local_service_unit_is_active(UNIT_NAME)
    puts "\nFINISHED: result for #{k} active: #{resp.bus.inspect}\n"
  end
end

threads = []

PARALLEL.times do |k|
  puts "building thread #{k + 1} out of #{PARALLEL}"
  threads << build_thread(k)
end

threads.each(&:join)

and the errors I get changes time to time but they all look like introspection data is not correct so it is not parsed properly

/home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:183:in `do_parse': DBus::InvalidPacketException (DBus::InvalidPacketException)
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:62:in `block in unmarshall'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:61:in `each'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:61:in `unmarshall'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/message.rb:201:in `unmarshall_buffer'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/message_queue.rb:139:in `message_from_buffer_nonblock'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/message_queue.rb:38:in `pop'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:441:in `wait_for_message'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:458:in `send_sync'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:339:in `send_sync_or_async'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:365:in `introspect_data'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/proxy_object.rb:73:in `introspect'
        from ./multiple_dbus_calls.rb:18:in `local_service_unit_is_active'
        from ./multiple_dbus_calls.rb:28:in `block in build_thread'
/home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:103:in `read_string': String is not nul-terminated (DBus::InvalidPacketException)
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:212:in `do_parse'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:62:in `block in unmarshall'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:61:in `each'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/marshall.rb:61:in `unmarshall'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/message.rb:227:in `unmarshall_buffer'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/message_queue.rb:139:in `message_from_buffer_nonblock'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/message_queue.rb:38:in `pop'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:441:in `wait_for_message'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:453:in `send_sync'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:339:in `send_sync_or_async'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/bus.rb:365:in `introspect_data'
        from /home/zaburt/.rvm/gems/ruby-2.4.3@dbus_test/gems/ruby-dbus-0.14.1/lib/dbus/proxy_object.rb:73:in `introspect'
        from ./multiple_dbus_calls.rb:18:in `local_service_unit_is_active'
        from ./multiple_dbus_calls.rb:28:in `block in build_thread'

You can find the sample script to reproduce the issue (no Rails, just Ruby) and some info here too https://github.com/zaburt/ruby-dbus-test . I can try out any test code or suggestions.

@mvidner
Copy link
Owner

mvidner commented Feb 28, 2018

Hi, thanks for the report!

In ruby-dbus, thread safety is more of an accident than a goal. That said, I think I have found a workaround for your use case:

-   sys_bus = DBus.system_bus
+   sys_bus = DBus::ASystemBus.new

which makes each thread use its own connection. With that, your example works for me. Does it help for you?

I should document that.

@zaburt
Copy link
Author

zaburt commented Mar 5, 2018

Thank you @mvidner that works very well ! I even tried the sample script with 200 threads running in parallel and did not see any issues. Will do more tests with Puma. Documenting this would be great as other people may hit this too.

I don't know if we should close this issue or wait for documentation update, or if you have something else in mind.

@mvidner
Copy link
Owner

mvidner commented Mar 5, 2018

Good to hear that! I'll document it and then close this myself.

mvidner added a commit that referenced this issue Mar 21, 2023
The previous attempt at thread safety failed (#7, #73)
but now I see a limited use case:

A worker thread only uses the shared bus connection to send signals
about its progress and completion. No method calls are accepted there.

That is, we only race for the bus connection in MessageQueue#push, not
in the #pop reading part.
mvidner added a commit that referenced this issue Mar 21, 2023
The previous attempt at thread safety failed (#7, #73)
but now I see a limited use case:

A worker thread only uses the shared bus connection to send signals
about its progress and completion. No method calls are accepted there.

That is, we only race for the bus connection in MessageQueue#push, not
in the #pop reading part.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants