phusion / passenger

A fast and robust web server and application server for Ruby, Python and Node.js
https://www.phusionpassenger.com/
MIT License
5.01k stars 547 forks source link

Action Cable processes getting killed when last session connection closes before "unsubscribe" finishes #2412

Open AhmedWaleedAhmed opened 2 years ago

AhmedWaleedAhmed commented 2 years ago

Question 1: What is the problem?

When Passenger process in a shutdown mode and we have our last session and this session dies when we have a big transaction like (5 sec) in the unsubscribe method to be done after the session is dead we will face an issue which is Passenger won't wait till this transaction ends it will kill it and roll back the transaction so the logic in unsubscribe method won't be done which can cause unwanted behaviors in future especially if it's related to information must be committed in the database to use it in future.

Be as detailed as possible in your descriptions, include any logs and stack traces (don't just cut/paste the error, provide some logging before that too).

(if you are requesting a feature instead of reporting an issue, describe here what you have in mind and how it would help you)

Your answer: I used a chatting app to test that

/app/assets/javascripts/channels/message.js App.message = App.cable.subscriptions.create("MessageChannel", { connected: function() { // Called when the subscription is ready for use on the server }, disconnected: function() { // Called when the subscription has been terminated by the server }, received(data) { const messageDisplay = document.querySelector('#message-display') messageDisplay.insertAdjacentHTML('beforeend', this.template(data)) }, template(data) { return `

${data.user.email}

${data.message.body}

` } }); document.addEventListener("turbolinks:load", () => { let form = document.querySelector('#message-form') if(form) { form.addEventListener('submit', (e) => { e.preventDefault() let messageInput = document.querySelector('#message-input').value if(messageInput == '') return; const message = { body: messageInput } App.message.send({message: message}) }) } })

/app/channels/application_cable/connection.rb module ApplicationCable class Connection < ActionCable::Connection::Base identified_by :current_user def connect self.current_user = find_verified_user end private def find_verified_user if verified_user = env['warden'].user verified_user else reject_unauthorized_connection end end end end

/app/channels/message_channel.rb class MessageChannel < ApplicationCable::Channel require "active_support/callbacks" require 'redis' before_unsubscribe { logger.info "we are in the function that will be executed before the unsubscribe work #######" ActiveRecord::Base.transaction do logger.info "We are creating a instance from redis" redis = Redis.new(host: "localhost") logger.info "we are setting the value of a to be 1" redis.set("a", 1) sleep(1) logger.info "we are trying to get this value now" redis.get("a")

Any cleanup needed when channel is unsubscribed

end } def subscribed stream_from 'message' end def unsubscribed logger.info ("unsubscribed the channel") end def receive(data) data['user'] = current_user ActionCable.server.broadcast('message', data) end end

/app/controllers/application_controller.rb class ApplicationController < ActionController::Base before_action :authenticate_user! end

/config/cable.yml production: adapter: redis url: <%= ENV.fetch("REDIS_URL") { "redis://localhost:6379/1" } %> channel_prefix: messenger_production local: &local adapter: redis url: redis://localhost:6379 development: local test: local

Question 2: Passenger version and integration mode: Your answer: open source 5.3.2 /nginx

Question 3: OS or Linux distro, platform (including version): Your answer: Ubuntu 20.04.3 LTS, x86-64

Question 4: Passenger installation method: Your answer: RubyGems + Gemfile

Question 5: Your app's programming language (including any version managers) and framework (including versions): Your answer: Ruby 2.7.0, Rails 5.2.5

Question 6: Are you using a PaaS and/or containerization? If so which one? Your answer: No

Question 7: Anything else about your setup that we should know?

Your answer: Logs

Started GET "/cable" for ::1 at 2022-01-21 22:37:41 +0200  (0.2ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC ↳ /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:107 Started GET "/cable/" [WebSocket] for ::1 at 2022-01-21 22:37:41 +0200 Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: upgrade, HTTP_UPGRADE: websocket) User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? ORDER BY "users"."id" ASC LIMIT ? [["id", 1], ["LIMIT", 1]] ↳ app/channels/application_cable/connection.rb:12 Registered connection (Z2lkOi8vbWVzc2VuZ2VyL1VzZXIvMQ) MessageChannel is transmitting the subscription confirmation MessageChannel is streaming from message Finished "/cable/" [WebSocket] for ::1 at 2022-01-21 22:37:56 +0200 we are in the function that will be executed before the unsubscribe work #######  (0.3ms) begin transaction ↳ app/channels/message_channel.rb:7 We are creating a instance from redis we are setting the value of a to be 1  (0.2ms) rollback transaction ↳ app/channels/message_channel.rb:7


CamJN commented 2 years ago

I don't know that there's a way for us to know if the work in unsubscribe has finished, would moving that transaction into a job system like active job work?

AhmedWaleedAhmed commented 2 years ago

I think moving it will work but will not solve the issue completely because if we failed to enqueue a job for any reason before the process gets killed we will also have the same issue.

I don't know if this can be done or not but if there is a way to trap the killing signal until the process is finished the transaction. this will eliminate the problem.