Fixed issue #2193 - Puma performance is going worst if users with phone attribute are updated or new tickets are created.

app/assets/javascripts/app/controllers/cti.coffee

@@ -25,6 +25,13 @@ class App.CTI extends App.Controller
       @delay(delay, 500, 'cti_list_push_render')
       'cti_list_push'
     )
+    @bind('cti_event', (data) =>
+      return if data.state isnt 'newCall'
+      return if data.direction isnt 'in'
+      return if @switch() isnt true
+      @notify(data)
+      'cti_event'
+    )
     @bind('auth', (data) =>
       @meta.counter = 0
     )
@@ -71,6 +78,7 @@ class App.CTI extends App.Controller
         # render new caller list
         if data.list
           @list = data.list
+          @updateNavMenu()
           if @renderDone
             @renderCallerLog()
             return
@@ -145,8 +153,8 @@ class App.CTI extends App.Controller
         if item.comment
           item.state_human += ", #{item.comment}"
 
-      if item.start && item.end
+      if item.start_at && item.end_at
-        item.duration = format((Date.parse(item.end) - Date.parse(item.start))/1000)
+        item.duration = format((Date.parse(item.end_at) - Date.parse(item.start_at))/1000)
 
       diff_in_min = ((Date.now() - Date.parse(item.created_at)) / 1000) / 60
       if diff_in_min > 1
@@ -198,9 +206,9 @@ class App.CTI extends App.Controller
   counter: =>
     count = 0
     for item in @list
-      if item.state is 'hangup' && !item.done
+      if !item.done
         count++
-    @meta.counter + count
+    @meta.counter = count
 
   switch: (state = undefined) =>
 

app/models/cti/caller_id.rb

@@ -113,9 +113,31 @@ returns
         caller_ids = caller_ids.concat(local_caller_ids)
       end
 
-      # store caller ids
+      # search for caller ids to keep
-      Cti::CallerId.where(object: model.to_s, o_id: record.id).destroy_all
+      caller_ids_to_add = []
-      caller_ids.each do |caller_id|
+      existing_record_ids = Cti::CallerId.where(object: model.to_s, o_id: record.id).pluck(:id)
+      caller_ids.uniq.each do |caller_id|
+        existing_record_id = Cti::CallerId.where(
+          object: model.to_s,
+          o_id: record.id,
+          caller_id: caller_id,
+          level: level,
+          user_id: user_id,
+        ).pluck(:id)
+        if existing_record_id[0]
+          existing_record_ids.delete(existing_record_id[0])
+          next
+        end
+        caller_ids_to_add.push caller_id
+      end
+
+      # delete not longer existing caller ids
+      existing_record_ids.each do |record_id|
+        Cti::CallerId.destroy(record_id)
+      end
+
+      # create new caller ids
+      caller_ids_to_add.each do |caller_id|
         Cti::CallerId.maybe_add(
           caller_id: caller_id,
           level: level,
@@ -251,10 +273,13 @@ returns
     end
 
     def update_cti_logs
+      return if object != 'User'
       UpdateCtiLogsByCallerJob.perform_later(caller_id)
     end
 
     def update_cti_logs_with_fg_optimization
+      return if object != 'User'
+      return if level != 'known'
       UpdateCtiLogsByCallerJob.perform_now(caller_id, limit: 20)
       UpdateCtiLogsByCallerJob.perform_later(caller_id, limit: 40, offset: 20)
     end

app/models/cti/log.rb

@@ -4,13 +4,13 @@ module Cti
 
     store :preferences
 
-    after_create :push_event, :push_caller_list
+    after_create :push_incoming_call, :push_caller_list_update
-    after_update :push_event, :push_caller_list
+    after_update :push_incoming_call, :push_caller_list_update
-    after_destroy :push_event, :push_caller_list
+    after_destroy :push_caller_list_update
 
 =begin
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '007',
     from_comment: 'AAA',
@@ -21,7 +21,7 @@ module Cti
     state: 'newCall',
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '007',
     from_comment: '',
@@ -32,7 +32,7 @@ module Cti
     state: 'answer',
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '009',
     from_comment: '',
@@ -45,13 +45,13 @@ module Cti
 
 example data, can be used for demo
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '4930609854180',
     from_comment: 'Franz Bauer',
     to: '4930609811111',
     to_comment: 'Bob Smith',
-    call_id: '00001',
+    call_id: '435452113',
     comment: '',
     state: 'newCall',
     done: false,
@@ -69,13 +69,13 @@ example data, can be used for demo
     }
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'out',
     from: '4930609854180',
     from_comment: 'Franz Bauer',
     to: '4930609811111',
     to_comment: 'Bob Smith',
-    call_id: '00002',
+    call_id: rand(999_999_999),
     comment: '',
     state: 'newCall',
     preferences: {
@@ -92,13 +92,13 @@ example data, can be used for demo
     }
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '4930609854180',
     from_comment: 'Franz Bauer',
     to: '4930609811111',
     to_comment: 'Bob Smith',
-    call_id: '00003',
+    call_id: rand(999_999_999),
     comment: '',
     state: 'answer',
     preferences: {
@@ -115,13 +115,13 @@ example data, can be used for demo
     }
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '4930609854180',
     from_comment: 'Franz Bauer',
     to: '4930609811111',
     to_comment: 'Bob Smith',
-    call_id: '00004',
+    call_id: rand(999_999_999),
     comment: '',
     state: 'hangup',
     comment: 'normalClearing',
@@ -140,13 +140,13 @@ example data, can be used for demo
     }
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '4930609854180',
     from_comment: 'Franz Bauer',
     to: '4930609811111',
     to_comment: 'Bob Smith',
-    call_id: '00005',
+    call_id: rand(999_999_999),
     comment: '',
     state: 'hangup',
     start_at: Time.zone.now - 15.seconds,
@@ -165,13 +165,13 @@ example data, can be used for demo
     }
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '4930609854180',
     from_comment: 'Franz Bauer',
     to: '4930609811111',
     to_comment: '',
-    call_id: '00006',
+    call_id: rand(999_999_999),
     comment: '',
     state: 'hangup',
     start_at: Time.zone.now - 15.seconds,
@@ -190,13 +190,13 @@ example data, can be used for demo
     }
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '4930609854180',
     from_comment: 'Franz Bauer',
     to: '4930609811111',
     to_comment: 'Bob Smith',
-    call_id: '00007',
+    call_id: rand(999_999_999),
     comment: '',
     state: 'hangup',
     start_at: Time.zone.now - 15.seconds,
@@ -215,11 +215,11 @@ example data, can be used for demo
     }
   )
 
-  Cti::Log.create(
+  Cti::Log.create!(
     direction: 'in',
     from: '4930609854180',
     to: '4930609811112',
-    call_id: '00008',
+    call_id: rand(999_999_999),
     comment: '',
     state: 'hangup',
     start_at: Time.zone.now - 20.seconds,
@@ -236,14 +236,14 @@ example data, can be used for demo
 returns
 
   {
-    list: [...]
+    list: [log_record1, log_record2, log_record3],
-    assets: {...}
+    assets: {...},
   }
 
 =end
 
     def self.log
-      list = Cti::Log.order('created_at DESC, id DESC').limit(60)
+      list = Cti::Log.log_records
 
       # add assets
       assets = list.map(&:preferences)
@@ -259,6 +259,20 @@ returns
       }
     end
 
+=begin
+
+  Cti::Log.log_records
+
+returns
+
+  [log_record1, log_record2, log_record3]
+
+=end
+
+    def self.log_records
+      Cti::Log.order('created_at DESC, id DESC').limit(60)
+    end
+
 =begin
 
 processes a incoming event
@@ -269,7 +283,7 @@ Cti::Log.process(
   'user' => 'user 1',
   'from' => '4912347114711',
   'to' => '4930600000000',
-  'callId' => '4991155921769858278-1', # or call_id
+  'callId' => '43545211', # or call_id
   'direction' => 'in',
 )
 
@@ -287,6 +301,7 @@ Cti::Log.process(
       from_comment = nil
       to_comment = nil
       preferences = nil
+      done = true
       if params['direction'] == 'in'
         to_comment = user
         from_comment, preferences = CallerId.get_comment_preferences(params['from'], 'from')
@@ -297,6 +312,9 @@ Cti::Log.process(
 
       case event
       when 'newCall'
+        if params['direction'] == 'in'
+          done = false
+        end
         create(
           direction: params['direction'],
           from: params['from'],
@@ -308,6 +326,7 @@ Cti::Log.process(
           state: event,
           initialized_at: Time.zone.now,
           preferences: preferences,
+          done: done,
         )
       when 'answer'
         log = find_by(call_id: call_id)
@@ -318,16 +337,19 @@ Cti::Log.process(
         if user
           log.to_comment = user
         end
+        log.done = true
         log.comment = comment
         log.save
       when 'hangup'
         log = find_by(call_id: call_id)
         raise "No such call_id #{call_id}" if !log
-        if params['direction'] == 'in' && log.state == 'newCall'
+        log.done = done
+        if params['direction'] == 'in'
+          if log.state == 'newCall'
+            log.done = false
+          elsif log.to_comment == 'voicemail'
             log.done = false
           end
-        if params['direction'] == 'in' && log.to_comment == 'voicemail'
-          log.done = false
         end
         log.state = 'hangup'
         log.end_at = Time.zone.now
@@ -343,7 +365,9 @@ Cti::Log.process(
       end
     end
 
-    def push_event
+    def push_incoming_call
+      return if state != 'newCall'
+      return if direction != 'in'
       users = User.with_permissions('cti.agent')
       users.each do |user|
 
@@ -358,8 +382,17 @@ Cti::Log.process(
       end
     end
 
-    def push_caller_list
+    def self.push_caller_list_update?(record)
-      list = Cti::Log.log
+      list_ids = Cti::Log.log_records.pluck(:id)
+      if list_ids.present?
+        last_caller_log = Cti::Log.find_by(id: list_ids.last)
+        return false if last_caller_log && last_caller_log.created_at > record.created_at - 1.day
+      end
+      true
+    end
+
+    def push_caller_list_update
+      return false if Cti::Log.push_caller_list_update?(self)
 
       users = User.with_permissions('cti.agent')
       users.each do |user|
@@ -369,10 +402,11 @@ Cti::Log.process(
           user.id,
           {
             event: 'cti_list_push',
-            data: list,
           },
         )
       end
+
+      true
     end
 
 =begin

test/controllers/integration_cti_controller_test.rb

@@ -279,7 +279,7 @@ class IntegrationCtiControllerTest < ActionDispatch::IntegrationTest
     assert_equal('CallerId Customer1', log.from_comment)
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
     assert(log.initialized_at)
     assert_nil(log.start_at)
     assert_nil(log.end_at)
@@ -339,7 +339,7 @@ class IntegrationCtiControllerTest < ActionDispatch::IntegrationTest
     assert_equal('CallerId Customer1', log.from_comment)
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
     assert(log.initialized_at)
     assert_nil(log.start_at)
     assert_nil(log.end_at)
@@ -399,7 +399,7 @@ class IntegrationCtiControllerTest < ActionDispatch::IntegrationTest
     assert_equal('CallerId Customer1', log.from_comment)
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
     assert(log.initialized_at)
     assert_nil(log.start_at)
     assert_nil(log.end_at)
@@ -441,7 +441,7 @@ class IntegrationCtiControllerTest < ActionDispatch::IntegrationTest
     assert(log.preferences['from'])
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
     assert(log.initialized_at)
     assert_nil(log.start_at)
     assert_nil(log.end_at)

test/controllers/integration_sipgate_controller_test.rb

@@ -308,7 +308,7 @@ class IntegrationSipgateControllerTest < ActionDispatch::IntegrationTest
     assert_equal('CallerId Customer1', log.from_comment)
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
 
     # inbound - I - answer by customer
     params = 'event=answer&direction=in&callId=1234567890-3&to=4930600000000&from=4912347114711'
@@ -353,7 +353,7 @@ class IntegrationSipgateControllerTest < ActionDispatch::IntegrationTest
     assert_equal('CallerId Customer1', log.from_comment)
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
 
     # inbound - II - answer by voicemail
     params = 'event=answer&direction=in&callId=1234567890-4&to=4930600000000&from=4912347114711&user=voicemail'
@@ -398,7 +398,7 @@ class IntegrationSipgateControllerTest < ActionDispatch::IntegrationTest
     assert_equal('CallerId Customer1', log.from_comment)
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
 
     # inbound - III - hangup by customer
     params = 'event=hangup&direction=in&callId=1234567890-5&cause=normalClearing&to=4930600000000&from=4912347114711'
@@ -430,7 +430,7 @@ class IntegrationSipgateControllerTest < ActionDispatch::IntegrationTest
     assert(log.preferences['from'])
     assert_nil(log.comment)
     assert_equal('newCall', log.state)
-    assert_equal(true, log.done)
+    assert_equal(false, log.done)
 
     # get caller list
     get '/api/v1/cti/log'

test/unit/cti_caller_id_test.rb

@@ -7,13 +7,11 @@ class CtiCallerIdTest < ActiveSupport::TestCase
 
     Ticket.destroy_all
     Cti::CallerId.destroy_all
-
     @agent1 = User.create_or_update(
       login: 'ticket-caller_id-agent1@example.com',
       firstname: 'CallerId',
       lastname: 'Agent1',
       email: 'ticket-caller_id-agent1@example.com',
-      password: 'agentpw',
       active: true,
       phone: '+49 1111 222222',
       fax: '+49 1111 222223',
@@ -27,7 +25,6 @@ class CtiCallerIdTest < ActiveSupport::TestCase
       firstname: 'CallerId',
       lastname: 'Agent2',
       email: 'ticket-caller_id-agent2@example.com',
-      password: 'agentpw',
       phone: '+49 2222 222222',
       note: 'Phone at home: <b>+49 2222 222224</b>',
       active: true,
@@ -39,7 +36,6 @@ class CtiCallerIdTest < ActiveSupport::TestCase
       firstname: 'CallerId',
       lastname: 'Agent3',
       email: 'ticket-caller_id-agent3@example.com',
-      password: 'agentpw',
       phone: '+49 2222 222222',
       active: true,
       updated_by_id: 1,
@@ -51,12 +47,13 @@ class CtiCallerIdTest < ActiveSupport::TestCase
       firstname: 'CallerId',
       lastname: 'Customer1',
       email: 'ticket-caller_id-customer1@example.com',
-      password: 'customerpw',
       active: true,
       updated_by_id: 1,
       created_by_id: 1,
     )
 
+    Observer::Transaction.commit
+    Scheduler.worker(true)
   end
 
   test '1 lookups' do
@@ -132,7 +129,8 @@ Mob: +49 333 1112222",
     )
     assert(ticket2)
 
-    Cti::CallerId.rebuild
+    Observer::Transaction.commit
+    Scheduler.worker(true)
 
     caller_ids = Cti::CallerId.lookup('491111222277')
     assert_equal(0, caller_ids.length)
@@ -327,4 +325,175 @@ Mob: +49 333 8362222",
 
   end
 
+  test '4 touch caller log / don\'t touch caller log'  do
+    5.times do |count|
+      travel 2.seconds
+      Cti::Log.process(
+        'cause' => '',
+        'event' => 'newCall',
+        'user' => 'user 1',
+        'from' => '491111222222',
+        'to' => '4930600000000',
+        'callId' => "touch-loop-#{count}",
+        'direction' => 'in',
+      )
+    end
+
+    # do not update Cti::Log on user touch
+    last_updated_at = Cti::Log.order(updated_at: :desc).first.updated_at
+    travel 10.minutes
+    @agent1.reload
+    @agent1.touch
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # do update old Cti::Log on phone update of user
+    @agent1.reload
+    @agent1.phone = '+49 1111 222222 999'
+    @agent1.save!
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_not_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # new call with not known number
+    travel 10.minutes
+    Cti::Log.process(
+      'cause' => '',
+      'event' => 'newCall',
+      'user' => 'user 1',
+      'from' => '49111122222277',
+      'to' => '4930600000000',
+      'callId' => 'touch-loop-20',
+      'direction' => 'in',
+    )
+
+    # set not known number for agent1
+    last_updated_at = Cti::Log.order(updated_at: :desc).first.updated_at
+    travel 10.minutes
+    @agent1.reload
+    @agent1.phone = '+49 1111 222222 77'
+    @agent1.save!
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_not_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # verify last updated entry
+    last = Cti::Log.order(updated_at: :desc).first
+    assert_equal('49111122222277', last.preferences[:from][0][:caller_id])
+    assert_nil(last.preferences[:from][0][:comment])
+    assert_equal('known', last.preferences[:from][0][:level])
+    assert_equal('User', last.preferences[:from][0][:object])
+    assert_equal(@agent1.id, last.preferences[:from][0][:o_id])
+
+    # create new user with no phone number
+    last_updated_at = Cti::Log.order(updated_at: :desc).first.updated_at
+    travel 30.minutes
+    agent4 = User.create!(
+      login: 'ticket-caller_id-agent4@example.com',
+      firstname: 'CallerId',
+      lastname: 'Agent4',
+      email: 'ticket-caller_id-agent4@example.com',
+      active: true,
+      updated_by_id: 1,
+      created_by_id: 1,
+    )
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # verify if caller log is updated with '' value for phone
+    agent4.reload
+    agent4.phone = ''
+    agent4.save!
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # verify if caller log is updated with nil value for phone
+    agent4.reload
+    agent4.phone = nil
+    agent4.save!
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+
+    # verify if caller log is updated with existing caller log value for phone
+    assert_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+    agent4.reload
+    agent4.phone = '+49 1111 222222'
+    agent4.save!
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_not_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # verify if caller log is no value change for phone
+    last_updated_at = Cti::Log.order(updated_at: :desc).first.updated_at
+    travel 30.minutes
+    agent4.save!
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # verify if caller log is updated with '' value for phone
+    last_updated_at = Cti::Log.order(updated_at: :desc).first.updated_at
+    travel 30.minutes
+    agent4.reload
+    agent4.phone = ''
+    agent4.save!
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_not_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+    # verify if caller log is updated if new ticket with existing caller id is created
+    last_updated_at = Cti::Log.order(updated_at: :desc).first.updated_at
+    travel 30.minutes
+    last_caller_id_count = Cti::CallerId.count
+    ticket1 = Ticket.create!(
+      title: 'some caller id test 1',
+      group: Group.lookup(name: 'Users'),
+      customer: @customer1,
+      state: Ticket::State.lookup(name: 'new'),
+      priority: Ticket::Priority.lookup(name: '2 normal'),
+      updated_by_id: @customer1.id,
+      created_by_id: @customer1.id,
+    )
+    article1 = Ticket::Article.create!(
+      ticket_id: ticket1.id,
+      from: 'some_sender@example.com',
+      to: 'some_recipient@example.com',
+      subject: 'some subject',
+      message_id: 'some@id',
+      body: "some message\n+49 1111 222222",
+      internal: false,
+      sender: Ticket::Article::Sender.where(name: 'Customer').first,
+      type: Ticket::Article::Type.where(name: 'email').first,
+      updated_by_id: @customer1.id,
+      created_by_id: @customer1.id,
+    )
+    Observer::Transaction.commit
+    Scheduler.worker(true)
+    assert_equal(last_caller_id_count + 2, Cti::CallerId.count)
+    assert_equal(last_updated_at, Cti::Log.order(updated_at: :desc).first.updated_at)
+
+  end
+
+  test '5 probe if caller log need to be pushed'  do
+
+    60.times do |count|
+      travel 1.hour
+      Cti::Log.process(
+        'cause' => '',
+        'event' => 'newCall',
+        'user' => 'user 1',
+        'from' => '491111222222',
+        'to' => '4930600000000',
+        'callId' => "touch-loop-#{count}",
+        'direction' => 'in',
+      )
+    end
+    assert(Cti::Log.push_caller_list_update?(Cti::Log.last))
+    assert_not(Cti::Log.push_caller_list_update?(Cti::Log.first))
+
+  end
+
 end