Merge branch 'develop' into jms_20250106_prod

src/core/callcenter/agent.py

@@ -7,7 +7,7 @@ import traceback
 from collections import defaultdict
 from concurrent.futures import ThreadPoolExecutor
 from typing import List
-
+from datetime import datetime
 from apscheduler.schedulers.background import BackgroundScheduler
 from sqlalchemy import or_
 
@@ -80,6 +80,8 @@ class AgentEventService:
 
     def agent_event_channel(self, event, call_info: CallInfo, device_info: DeviceInfo):
         event_name = EslEventUtil.getEventName(event)
+        event_timestamp = EslEventUtil.getEventTimestamp(event)
+        event_time = datetime.fromtimestamp(event_timestamp).strftime('%Y-%m-%d %H:%M:%S')
         saas_id = call_info.saas_id if call_info else None
         flow_id = call_info.cti_flow_id if call_info else None
         call_id = call_info.call_id if call_info else None
@@ -91,14 +93,14 @@ class AgentEventService:
 
         start_time = time.time()
         try:
-            self.logger.info('agent_event_channel, event_name=%s, call_id=%s, agent_num=%s, device_id=%s, is_agent=%s, hangup_dir=%s, hangup_count=%s, answer_count=%s', event_name, call_id, agent_num, device_id, is_agent, call_info.hangup_dir, call_info.hangup_count, call_info.answer_count)
+            self.logger.info('agent_event_channel, event_name=%s, call_id=%s, event_time=%s, agent_num=%s, device_id=%s, is_agent=%s, hangup_dir=%s, hangup_count=%s, answer_count=%s', event_name, call_id, event_time, agent_num, device_id, is_agent, call_info.hangup_dir, call_info.hangup_count, call_info.answer_count)
             agent = self.data_handle_server.get_agent(saas_id, agent_num)
             if not agent:
-                # self.logger.warn("event service channel agent is null %s %s %s %s %s", saas_id, event_name, caller, called, json.loads(event.serialize('json')))
+                self.logger.warn("agent_event_channel:return, agent is null %s %s %s %s %s", saas_id, event_name, event_time, caller, called)
                 return
             agent_monitor = self.data_handle_server.get_agent_monitor(saas_id, agent_num)
             if not agent_monitor:
-                # self.logger.warn("event service channel agentMonitor is null %s %s %s %s %s", saas_id, event_name, caller, called, json.loads(event.serialize('json')))
+                self.logger.warn("agent_event_channel:return, agentMonitor is null %s %s %s %s %s", saas_id, event_name, event_time, caller, called)
                 return
 
             # 信道发起事件，触发完成发起（或桥）&& 坐席侧
@@ -175,11 +177,16 @@ class AgentEventService:
         except:
             traceback.print_exc()
         finally:
-            latency = (time.time() - start_time)
+            time_cost = (time.time() - start_time) * 1000
+            registry.ESL_EVENT_CALLBACK_COST.labels(event_name, "agent").observe(time_cost)
+            latency = (time.time() - event_timestamp) * 1000
             registry.ESL_EVENT_CALLBACK_LATENCY.labels(event_name, "agent").observe(latency)
+            self.logger.info('agent_event_channel, event_name=%s, time_cost=%s, latency=%s, call_id=%s, event_time=%s, agent_num=%s, device_id=%s, is_agent=%s, hangup_dir=%s, hangup_count=%s, answer_count=%s', event_name, time_cost, latency, call_id, event_time, agent_num, device_id, is_agent, call_info.hangup_dir, call_info.hangup_count, call_info.answer_count)
 
     def bot_event_channel(self, event, call_info, device_info):
         event_name = EslEventUtil.getEventName(event)
+        event_timestamp = EslEventUtil.getEventTimestamp(event)
+        event_time = datetime.fromtimestamp(event_timestamp).strftime('%Y-%m-%d %H:%M:%S')
         saas_id = call_info.saas_id if call_info else None
         flow_id = call_info.cti_flow_id if call_info else None
         call_id = call_info.call_id if call_info else None
@@ -192,26 +199,24 @@ class AgentEventService:
 
         start_time = time.time()
         try:
-            self.logger.info('bot_event_channel, event_name=%s, call_id=%s, device_id=%s, is_agent=%s, agent_num=%s, hangup_dir=%s, hangup_count=%s, answer_count=%s', event_name, call_id, device_id, is_agent, agent_num, call_info.hangup_dir, call_info.hangup_count, call_info.answer_count)
+            self.logger.info('bot_event_channel, event_name=%s, call_id=%s, device_id=%s, event_time=%s, is_agent=%s, agent_num=%s, hangup_dir=%s, hangup_count=%s, answer_count=%s', event_name, call_id, device_id, event_time, is_agent, agent_num, call_info.hangup_dir, call_info.hangup_count, call_info.answer_count)
             agent = self.data_handle_server.get_agent(saas_id, agent_num)
             if not agent:
-                # self.logger.warn("bot event service channel agent is null %s %s %s %s %s", saas_id, event_name, caller, called,
-                #                  json.dumps(event.serialize('json')))
+                self.logger.warn("bot_event_channel:return, agent is null %s %s %s %s %s %s", saas_id, event_name, event_time, call_id, caller, called)
                 return
             agent_monitor = self.data_handle_server.get_agent_monitor(saas_id, agent_num)
             if not agent_monitor:
-                # self.logger.warn("bot event service channel agentMonitor is null %s %s %s %s %s", saas_id, event_name, caller,
-                #                  called, json.dumps(event.serialize('json')))
+                self.logger.warn("bot_event_channel:return, agentMonitor is null %s %s %s %s %s %s ", saas_id, event_name, event_time, call_id, caller, called)
                 return
 
             # 信道发起事件，触发完成发起（或桥）&& 坐席侧
             if CHANNEL_ORIGINATE == event_name and is_agent:
-                self.data_handle_server.update_record(call_id, transfer_user_id=agent.user_id,transfer_user_name=agent.agent_name)  # 转接给客服以后更新转接人
                 # if call_info.hangup_dir and call_info.hangup_dir == HangupDir.CUSTOMER_HANGUP.code:
                 #     self.logger.info('bot_event_channel:already:hangup, event_name=%s, call_id=%s, device_id=%s, is_agent=%s, agent_num=%s, hangup_dir=%s, hangup_count=%s, answer_count=%s', event_name, call_id, device_id, is_agent, agent_num, call_info.hangup_dir, call_info.hangup_count, call_info.answer_count)
                     # return
                 self.push_handler.push_on_call_ring(saas_id, flow_id, agent_num, AgentScene.ROBOT, call_id, ServiceDirect.ROBOT_CALL.service_direct, called, caller, human_service_id)
                 self.push_handler.push_on_agent_work_report(saas_id, flow_id, agent_num, call_id, AgentScene.ROBOT, WorkStatus.AGENT_RINGING,phone=call_info.caller)
+                self.data_handle_server.update_record(call_id, transfer_user_id=agent.user_id,transfer_user_name=agent.agent_name)  # 转接给客服以后更新转接人
 
 
             if CHANNEL_ANSWER == event_name:
@@ -242,8 +247,11 @@ class AgentEventService:
         except:
             traceback.print_exc()
         finally:
-            latency = (time.time() - start_time)
-            registry.ESL_EVENT_CALLBACK_LATENCY.labels(event_name, "agent").observe(latency)
+            time_cost = (time.time() - start_time) * 1000
+            registry.ESL_EVENT_CALLBACK_COST.labels(event_name, "bot").observe(time_cost)
+            latency = (time.time() - event_timestamp) * 1000
+            registry.ESL_EVENT_CALLBACK_LATENCY.labels(event_name, "bot").observe(latency)
+            self.logger.info('bot_event_channel, event_name=%s, time_cost=%s, latency=%s, call_id=%s, device_id=%s, event_time=%s, is_agent=%s, agent_num=%s, hangup_dir=%s, hangup_count=%s, answer_count=%s', event_name, time_cost, latency, call_id, device_id, event_time, is_agent, agent_num, call_info.hangup_dir, call_info.hangup_count, call_info.answer_count)
 
     def reprocessing_idle(self, state_data: AgentDelayStateData):
         agent = self.data_handle_server.get_agent(state_data.saas_id, state_data.agent_num)
@@ -1057,10 +1065,11 @@ class AgentStateService:
         return "CTI:%s:HUMAN:%s:%s:LOCK"%(saas_id.upper(), service_id, choose_phone_num)
 
     def _get_expire_time(self):
-        now = datetime.now()
-        end_of_day = now.replace(hour=23, minute=59, second=59, microsecond=0)
-        expire_time = (end_of_day - now).total_seconds()  # Convert to milliseconds
-        return int(expire_time)
+        # now = datetime.now()
+        # end_of_day = now.replace(hour=23, minute=59, second=59, microsecond=0)
+        # expire_time = (end_of_day - now).total_seconds()  # Convert to milliseconds
+        # return int(expire_time)
+        return 60*60*24*30
 
     def _choose_max_idle_time(self, idle_agents: List[AgentStateData]) -> str:
         idle_agents = sorted(idle_agents, key=lambda agent: agent.assign_time, reverse=False)

src/core/callcenter/esl/client.py

@@ -115,7 +115,7 @@ class InboundClient:
             random_index = abs(mmh3.hash(random_id)) % len(self.executors)
         else:
             random_index = random.randint(0, len(self.executors) - 1) if self.executors else 0
-        self.logger.info('choose_thread_pool_executor:event_name=%s, random_index=%s, call_id=%s, unique_id=%s, device_id=%s, ', event_name, random_index, call_id, device_id, wdh_device_id)
+        # self.logger.info('choose_thread_pool_executor:event_name=%s, random_index=%s, call_id=%s, unique_id=%s, device_id=%s, event_time=%s', event_name, random_index, call_id, device_id, wdh_device_id, event_time)
         return self.executors.get(random_index)
 
     def process_esl_event(self, e):
@@ -123,8 +123,13 @@ class InboundClient:
         start_time = time.time()
         event_name = EslEventUtil.getEventName(e)
         coreUUID = EslEventUtil.getCoreUuid(e)
+        call_id = EslEventUtil.getCallId(e)
+        device_id = EslEventUtil.getUniqueId(e)
+        wdh_device_id = EslEventUtil.getDeviceId(e)
+        event_timestamp = EslEventUtil.getEventTimestamp(e)
+        event_time = datetime.fromtimestamp(event_timestamp).strftime('%Y-%m-%d %H:%M:%S')
         address = self.host + ':' + self.port
-        # self.logger.info("process_esl_event.event_name=%s,coreUUID=%s", event_name, coreUUID)
+        self.logger.info('process_esl_event:event_name=%s, call_id=%s, unique_id=%s, device_id=%s, event_time=%s', event_name, call_id, device_id, wdh_device_id, event_time)
         try:
             self.callback.callback_event(e)
             if event_name in self.handler_table:
@@ -140,8 +145,11 @@ class InboundClient:
         except:
             traceback.print_exc()
         finally:
-            latency = (time.time() - start_time)
+            time_cost = (time.time() - start_time) * 1000
+            registry.ESL_EVENT_COST.labels(event_name).observe(time_cost)
+            latency = (time.time() - event_timestamp) * 1000
             registry.ESL_EVENT_LATENCY.labels(event_name).observe(latency)
+            self.logger.info('process_esl_event:event_name=%s, time_cost=%s, latency=%s, call_id=%s, unique_id=%s, device_id=%s, event_time=%s', event_name, time_cost, latency, call_id, device_id, wdh_device_id, event_time)
 
     def do_delay_action(self, action, message):
         delay_action = DelayAction.from_json(message)

src/core/callcenter/esl/utils/esl_event_util.py

@@ -1,6 +1,7 @@
 #!/usr/bin/env python3
 # encoding:utf-8
 
+import time
 import random
 import re
 import string
@@ -231,6 +232,10 @@ def getFreeswitchSwitchname(e):
 def getEventDateTimestamp(e):
     return e.getHeader(EVENT_DATE_TIMESTAMP)
 
+def getEventTimestamp(e):
+    event_timestamp = getEventDateTimestamp(e)
+    event_timestamp_sec = float(event_timestamp) / 1_000_000 if event_timestamp else time.time()
+    return event_timestamp_sec
 
 def getEventSubClass(e):
     return e.getHeader(EVENT_SUB_CLASS)

src/core/callcenter/registry.py

@@ -28,7 +28,9 @@ ASR_ERRORS = Counter( 'asr_error_codes', 'Count of ASR error codes', ['errorCode
 
 
 # esl时间耗时
+ESL_EVENT_COST = Histogram('esl_event_cost', 'Esl Event process cost in seconds', ['eventName'])
 ESL_EVENT_LATENCY = Histogram('esl_event_latency', 'Esl Event latency in seconds', ['eventName'])
+ESL_EVENT_CALLBACK_COST = Histogram('esl_event_callback_cost', 'Esl Event callback process cost in seconds', ['eventName','callType'])
 ESL_EVENT_CALLBACK_LATENCY = Histogram('esl_event_callback_latency', 'Esl Event callback latency in seconds', ['eventName','callType'])