The HIS log is structured as a flat line based file. Each event starts on a new line and can span multiple lines based on the event type and content. Here’s an example event:
2023-06-13_14:59:39.445 UTC INFO PureCloudConversation PureCloud-rajat1.88102.88102.OM145908759400000001.c3fbc3cd-20c3-408a-b035-1a7d05322d91 - Object State: Conversation Member Added: sip:3e6406b6-c086-4482-b99f-fff74f9e0b88@127.0.0.1
An event has two major sections separated by <space> - <space>. The preamble section contains meta-data about the event including timestamp and level. The content section contains the actual event information. Let’s break down the example event into its sections.
Preamble Section
2023-06-13_14:59:39.445 UTC INFO PureCloudConversation PureCloud-rajat1.88102.88102.OM145908759400000001.c3fbc3cd-20c3-408a-b035-1a7d05322d91
The preamble section can be further divided into 4 data points: timestamp, level, source, and context.
Timestamp
Each event starts with a timestamp that records the time the event occurred at millisecond granularity. The timestamp format can be written as yyyy-MM-dd_hh:mm:ss.SSS Z in regex notation. This format is used to allow canonical comparison and sorting with values remaining in chronological order when in ascending order. The hour portion is written using the 24 hour clock (military time). The timezone of the event is the last portion and uses the standard 3 letter designation.
Level
Events can be one of 4 severities:
ERROR
WARN
INFO
DEBUG
The level always occupies 5 characters in the event with WARN and INFO being left aligned and having an extra <space> as padding. When setting log level, you chose the level to write which always includes the levels above that level. For instance setting the log level to INFO includes WARN and ERROR. Setting the level to ERROR will only generate ERROR level messages.
Source
The event source represents the internal component or object type that generated the event. The example event was generated by a PureCloudConversation object. This field does not contain <space>s to assist in parsing the event.
Context
The context field provides further details about the event source. Ownership information is provided in “dot” notation with each item owning the items that come after a '.'. The example event context provides the entire object hierarchy for the conversation:
PureCloud-rajat1 - The agent session id
88102 - The channel group id
88102 - The channel id
OM145908759400000001 - The interaction id
c3fbc3cd-20c3-408a-b035-1a7d05322d91 - The conversation id
The context field helps filter the log contents. For example you could see all the logs related to a particular agent session by searching for ‘PureCloud-rajat1’ since all logs, even those for child objects, will have a context field that starts with that value.
Content Section
Object State: Conversation Member Added: sip:3e6406b6-c086-4482-b99f-fff74f9e0b88@127.0.0.1
The content section is a free-form area that contains details about the event. Although there is no standard structure to the content section, there are similarities between related events. The remainder of this document will have examples of important and common events.
System Startup
2023-06-13_14:58:24.351 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.avaya] 2023-06-13_14:58:24.351 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.genesys] 2023-06-13_14:58:24.351 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.incontact] 2023-06-13_14:58:24.352 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.incontact.hub] 2023-06-13_14:58:24.352 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.bridge] 2023-06-13_14:58:24.352 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.uccx] 2023-06-13_14:58:24.352 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.five9] 2023-06-13_14:58:24.352 UTC INFO ProcessorManagement - New processor factory [com.openmethods.ep.config.model.interactionprocessor.purecloud] 2023-06-13_14:58:24.352 UTC INFO ProcessorManagement - Activating processor management 2023-06-13_14:58:24.832 UTC INFO ProcessorManagement - Retrieving configuration from Config Server: https://cs.qa.openmethodscloud.com//work/v1/customers/348aa9f80e5647eb9223d06925ef7eb4/networkhosts/c4733e18-69f1-4708-b05a-a88d5aec1222/networkhostservices/ebaa72ce-b1ab-44aa-abcc-690363b57737/gethisconfig
When HIS starts up, it lists the types of telephony platforms the build supports. In the example, this is covered by the first 8 lines. Next it initializes the processor management component (line 9) and retrieves its configuration from Config Server (line 10). If you see these events, it means that HIS was restarted. Depending on the configuration provided by Config Server you will see one or more events:
2023-06-13_14:58:26.330 UTC INFO ProcessorManagement - Received service config: {"interactionProcessorId":"1736a3b1-dc32-4459-bc1d-3f156a318bde","interactionProcessorType":"com.openmethods.ep.config.model.interactionprocessor.avaya","extensions":[],"environment":{"environmentId":"61a7e295-5dd9-4658-84b1-ddfe8a892e2b","environmentName":"Avaya","environmentType":"com.openmethods.ep.config.model.environment.avaya","extensions":[{"namespace":"disposition.settings","data":{"dispositionEditable":false,"dispositionMaxLength":20,"dispositionRequired":false}},{"namespace":"environment.feature.settings","data":{"interactionDataEditable":true,"enableLogoutReasons":true,"ExternalQuickDial":false,"enableCountryCodes":false,"ForceAgentLogoutOnExit":false,"enableCallerId":false,"DisableSSO":false,"disableExternalNotReadyReasons":false,"AutoActivateChannels":false,"DisableAgentUpdate":false,"AgentSelectEditable":true,"enableDisposition":false,"enableCTIBridge":false}},{"namespace":"outbound.dial.rules","data":{"removeSpecialCharacters":false,"removeLeadingPlus":false,"removeLeading1":false,"dialPrefix":"","internationalDialPrefix":"","maxLength":40}},{"namespace":"avaya.environment.settings","data":{"TLinkName":"AVAYA#IBOMAVAYACM153#CSTA#IBOMAVAYAAES155","PrimaryAESPort":450,"ACWPollingTime":3000,"UUIFixedFormat":"","AESUser":"Tsapi_User","BackupAESAddress":"","UUIFormat":"URLEncoded","AESPassword":"Tsapi_User","PrimaryAESAddress":"192.168.28.155","AutoRetrieveEnabled":false,"BackupAESPort":450}},{"namespace":"agent.channel.settings","data":{"autoAnswerEmail":false,"autoAnswerPhone":false,"voicemail":false,"autoAnswerChat":false,"name":"","chat":true,"callbacks":false,"endCompletesInteraction":false,"email":true}}]}}
The json included in the event describes the processor configuration including its type "interactionProcessorType":"com.openmethods.ep.config.model.interactionprocessor.avaya"
, in this case Avaya. For each of these configurations, HIS will create a new processor component and initialize it. The initialization process can have minor differences depending on the platform type but they all follow a similar pattern.
2023-06-13_14:58:26.400 UTC INFO ProcessorManagement - Attempting to initiate processor: {"interactionProcessorId":"1736a3b1-dc32-4459-bc1d-3f156a318bde","interactionProcessorType":"com.openmethods.ep.config.model.interactionprocessor.avaya","extensions":[],"environment":{"environmentId":"61a7e295-5dd9-4658-84b1-ddfe8a892e2b","environmentName":"Avaya","environmentType":"com.openmethods.ep.config.model.environment.avaya","extensions":[{"namespace":"disposition.settings","data":{"dispositionEditable":false,"dispositionMaxLength":20,"dispositionRequired":false}},{"namespace":"environment.feature.settings","data":{"interactionDataEditable":true,"enableLogoutReasons":true,"ExternalQuickDial":false,"enableCountryCodes":false,"ForceAgentLogoutOnExit":false,"enableCallerId":false,"DisableSSO":false,"disableExternalNotReadyReasons":false,"AutoActivateChannels":false,"DisableAgentUpdate":false,"AgentSelectEditable":true,"enableDisposition":false,"enableCTIBridge":false}},{"namespace":"outbound.dial.rules","data":{"removeSpecialCharacters":false,"removeLeadingPlus":false,"removeLeading1":false,"dialPrefix":"","internationalDialPrefix":"","maxLength":40}},{"namespace":"avaya.environment.settings","data":{"TLinkName":"AVAYA#IBOMAVAYACM153#CSTA#IBOMAVAYAAES155","PrimaryAESPort":450,"ACWPollingTime":3000,"UUIFixedFormat":"","AESUser":"Tsapi_User","BackupAESAddress":"","UUIFormat":"URLEncoded","AESPassword":"Tsapi_User","PrimaryAESAddress":"192.168.28.155","AutoRetrieveEnabled":false,"BackupAESPort":450}},{"namespace":"agent.channel.settings","data":{"autoAnswerEmail":false,"autoAnswerPhone":false,"voicemail":false,"autoAnswerChat":false,"name":"","chat":true,"callbacks":false,"endCompletesInteraction":false,"email":true}}]}} 2023-06-13_14:58:26.568 UTC INFO AvayaProcessor Avaya - Starting plugin... 2023-06-13_14:58:26.571 UTC INFO AvayaProcessor Avaya - Starting Avaya JTAPI Plugin... 2023-06-13_14:58:26.573 UTC INFO AvayaProcessor Avaya - Connecting Avaya to AES: AVAYA#IBOMAVAYACM153#CSTA#IBOMAVAYAAES155;login=Tsapi_User;passwd=Tsapi_User;servers=192.168.28.155:450 2023-06-13_14:58:26.765 UTC INFO c.a.j.tsapi.impl.core.TSProviderImpl - TSProvider: version '7.0.0.64 [production build]', for TSProvider[#1]@1c058977
All processors regardless of type will start with a Starting plugin… event (line 2). Lines 3 & 4 are specific to the Avaya platform and indicate that the plugin is attempting to connect to AES. Line 5 is an example of the Avaya third-party library log events. For the most part these events can be ignored unless a very detailed review is needed to identify a product issue.
2023-06-13_14:58:27.683 UTC INFO AvayaProcessor Avaya - Plugin started.
Once a processor has successfully completed its initialization the above event will be generated. In the case of failure, a Plugin failed to start event is generated instead with further events that indicate the reason for failure.
Work Engine
HIS at its core is the middle-man between the agent’s media bar and the telephony platform. Requests and events can come from either side at any time. To ensure things are processed in the right order, HIS has a built in work engine component. New events or requests are added to a pair of work queues dedicated to the agent’s session; one for the media bar end and one for the telephony platform side. These queues produce debug log events as they process tasks:
2023-06-13_14:58:27.829 UTC DEBUG WorkEngine DirectClients - Inspecting Queue: media-bar rajat.gupta@openmethods.com.12778f90-8838-4779-ac73-99ad177cf085.inbound Size: 1 2023-06-13_14:58:27.829 UTC DEBUG WorkEngine DirectClients - Dequeued 1 items from media-bar rajat.gupta@openmethods.com.12778f90-8838-4779-ac73-99ad177cf085.inbound 2023-06-13_14:58:27.829 UTC DEBUG WorkEngine DirectClients - Looking for idle thread 2023-06-13_14:58:27.829 UTC DEBUG WorkEngine DirectClients.1 - Processing: media-bar rajat.gupta@openmethods.com.12778f90-8838-4779-ac73-99ad177cf085.inbound 1 2023-06-13_14:58:27.830 UTC DEBUG WorkEngine DirectClients.1 - Item: 0 Age: 0 InboundMessage: {"messageType":"coreRequest","requestId":"1bfc004b-386a-4ad6-a3aa-6c1a2a7f7adf","command":"getService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:27.830 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"messageType":"coreRequest","requestId":"1bfc004b-386a-4ad6-a3aa-6c1a2a7f7adf","command":"getService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:27.832 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"coreResponse","requestId":"1bfc004b-386a-4ad6-a3aa-6c1a2a7f7adf","command":"getService","service":{"id":"e70f36a4-982f-47e2-9420-780ebe581f36","name":"PureCloud","type":"com.openmethods.iserver.processor","serviceStatus":{"status":"Starting","acceptingClients":false,"clientCount":0},"info":{"vendor":"OpenMethods","version":"4.0.0","cti-vendor":"PureCloud","instance-domain":"PureCloud"}}} 2023-06-13_14:58:27.832 UTC DEBUG WorkEngine DirectClients.1 - Item 0 done in 3 InboundMessage: {"messageType":"coreRequest","requestId":"1bfc004b-386a-4ad6-a3aa-6c1a2a7f7adf","command":"getService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:27.832 UTC DEBUG WorkEngine DirectClients.1 - Finished with queue processing 2023-06-13_14:58:27.832 UTC DEBUG WorkEngine DirectClients.1 - Removing queue lock for media-bar rajat.gupta@openmethods.com.12778f90-8838-4779-ac73-99ad177cf085.inbound 2023-06-13_14:58:27.833 UTC DEBUG WorkEngine DirectClients.1 - Going back to idle pool
The first three lines are the work engine inspecting the media bar queue for tasks (line 1), dispatching the task to a worker thread (line 2), and then returning back to the thread pool. The remaining log entries are produced by the worker thread as it processes the task. Line 5 has important information related to task timing. The Age: value is the number of milliseconds the task has been waiting in queue. In the example, the task was picked up as soon as it was queued resulting in the 0 value. Lines 6 & 8 are log events generated by the task while being executed. Line 6 is also an example of a multiline event with Line 7 being the continuation of the event that starts on Line 6. Line 9 again provides additional timing information about how many milliseconds it took to complete the task. The last 3 lines are the worker thread cleaning up after the task and returning to the thread pool.
Agent Login
An agent login is probably the most complicated process handled by HIS and generates a large set of events.
2023-06-13_14:58:27.828 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Request Received: {"messageType":"coreRequest","requestId":"1bfc004b-386a-4ad6-a3aa-6c1a2a7f7adf","command":"getService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:27.830 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"messageType":"coreRequest","requestId":"1bfc004b-386a-4ad6-a3aa-6c1a2a7f7adf","command":"getService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:27.832 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"coreResponse","requestId":"1bfc004b-386a-4ad6-a3aa-6c1a2a7f7adf","command":"getService","service":{"id":"e70f36a4-982f-47e2-9420-780ebe581f36","name":"PureCloud","type":"com.openmethods.iserver.processor","serviceStatus":{"status":"Starting","acceptingClients":false,"clientCount":0},"info":{"vendor":"OpenMethods","version":"4.0.0","cti-vendor":"PureCloud","instance-domain":"PureCloud"}}}
When an agent logs into the media bar, the media bar first contacts all available HIS servers to get information about their current status and load. The status property indicates the general state of the processor. The acceptingClients property determines if the processor is currently accepting new clients. The clientCount property is the total number of clients that have bound to the service. The media bar uses this information to select the HIS that is accepting clients and has the lowest load (connected clients).
2023-06-13_14:58:33.218 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Request Received: {"messageType":"coreRequest","requestId":"56405ddd-0073-415c-9f55-9c9953831143","command":"bindService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients - Inspecting Queue: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound Size: 1 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients - Dequeued 1 items from media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients - Looking for idle thread 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients.1 - Processing: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 1 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients.1 - Item: 0 Age: 0 InboundMessage: {"messageType":"coreRequest","requestId":"56405ddd-0073-415c-9f55-9c9953831143","command":"bindService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:33.219 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"messageType":"coreRequest","requestId":"56405ddd-0073-415c-9f55-9c9953831143","command":"bindService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:33.219 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"coreResponse","requestId":"56405ddd-0073-415c-9f55-9c9953831143","command":"bindService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","serviceName":"PureCloud","serviceType":"com.openmethods.iserver.processor","result":"success"} 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients.1 - Item 0 done in 0 InboundMessage: {"messageType":"coreRequest","requestId":"56405ddd-0073-415c-9f55-9c9953831143","command":"bindService","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients.1 - Finished with queue processing 2023-06-13_14:58:33.219 UTC DEBUG WorkEngine DirectClients.1 - Removing queue lock for media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:33.220 UTC DEBUG WorkEngine DirectClients.1 - Going back to idle pool 2023-06-13_14:58:33.323 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Request Received: {"messageType":"coreRequest","requestId":"140363ab-28ad-458b-b76f-f98130aec870","command":"bindService","serviceId":"WorkflowManager"} 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients - Inspecting Queue: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound Size: 1 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients - Dequeued 1 items from media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients - Looking for idle thread 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients.2 - Processing: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 1 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients.2 - Item: 0 Age: 0 InboundMessage: {"messageType":"coreRequest","requestId":"140363ab-28ad-458b-b76f-f98130aec870","command":"bindService","serviceId":"WorkflowManager"} 2023-06-13_14:58:33.323 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"messageType":"coreRequest","requestId":"140363ab-28ad-458b-b76f-f98130aec870","command":"bindService","serviceId":"WorkflowManager"} 2023-06-13_14:58:33.323 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"coreResponse","requestId":"140363ab-28ad-458b-b76f-f98130aec870","command":"bindService","serviceId":"WorkflowManager","serviceName":"WorkflowManager","serviceType":"com.openmethods.iserver.workflow.manager","result":"success"} 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients.2 - Item 0 done in 0 InboundMessage: {"messageType":"coreRequest","requestId":"140363ab-28ad-458b-b76f-f98130aec870","command":"bindService","serviceId":"WorkflowManager"} 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients.2 - Finished with queue processing 2023-06-13_14:58:33.323 UTC DEBUG WorkEngine DirectClients.2 - Removing queue lock for media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:33.324 UTC DEBUG WorkEngine DirectClients.2 - Going back to idle pool
Once an HIS instance is selected, the media bar binds to the processor and workflow components. Binding to a component allows a client to access that component’s API and receive events produced by it.
2023-06-13_14:58:34.699 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Request Received: {"requestId":"1062ccea-c1de-4d75-a2ed-f370d82a8df7","request":{"command":"getCapabilities","data":""},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:34.699 UTC DEBUG WorkEngine DirectClients - Inspecting Queue: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound Size: 1 2023-06-13_14:58:34.699 UTC DEBUG WorkEngine DirectClients - Dequeued 1 items from media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:34.699 UTC DEBUG WorkEngine DirectClients - Looking for idle thread 2023-06-13_14:58:34.699 UTC DEBUG WorkEngine DirectClients.3 - Processing: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 1 2023-06-13_14:58:34.699 UTC DEBUG WorkEngine DirectClients.3 - Item: 0 Age: 0 InboundMessage: {"requestId":"1062ccea-c1de-4d75-a2ed-f370d82a8df7","request":{"command":"getCapabilities","data":""},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:34.699 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"requestId":"1062ccea-c1de-4d75-a2ed-f370d82a8df7","request":{"command":"getCapabilities","data":""},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:34.699 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"serviceResponse","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","requestId":"1062ccea-c1de-4d75-a2ed-f370d82a8df7","response":{"command":"getCapabilities","result":"success","data":{"channel-groups-max-per-agent":"0","single-channels-media-types":"","channel-actions":"first","channel-groups-media-types":"","channel-groups-supported":"false","single-channels-supported":"true"}}} 2023-06-13_14:58:34.699 UTC DEBUG WorkEngine DirectClients.3 - Item 0 done in 0 InboundMessage: {"requestId":"1062ccea-c1de-4d75-a2ed-f370d82a8df7","request":{"command":"getCapabilities","data":""},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:34.700 UTC DEBUG WorkEngine DirectClients.3 - Finished with queue processing 2023-06-13_14:58:34.700 UTC DEBUG WorkEngine DirectClients.3 - Removing queue lock for media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:34.700 UTC DEBUG WorkEngine DirectClients.3 - Going back to idle pool 2023-06-13_14:58:34.762 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Request Received: {"requestId":"5b21f472-c7d2-41ae-91e2-a42813beeade","request":{"command":"prepareSession","data":{"agent":{"id":"rajat1","password":"snu6XMUjEBstKXGhLkVQ0qvnGxQ3OwddLXgfobUpK2yW1Xql-b8uAf0nlJ4q4UpFowYCUUe1_UX6qHNdy8PP5w"},"model":"RNA-PureCloud","override":true,"cti":"e70f36a4-982f-47e2-9420-780ebe581f36"}},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:34.763 UTC DEBUG WorkEngine DirectClients - Inspecting Queue: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound Size: 1 2023-06-13_14:58:34.763 UTC DEBUG WorkEngine DirectClients - Dequeued 1 items from media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:34.763 UTC DEBUG WorkEngine DirectClients - Looking for idle thread 2023-06-13_14:58:34.763 UTC DEBUG WorkEngine DirectClients.5 - Processing: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 1 2023-06-13_14:58:34.763 UTC DEBUG WorkEngine DirectClients.5 - Item: 0 Age: 0 InboundMessage: {"requestId":"5b21f472-c7d2-41ae-91e2-a42813beeade","request":{"command":"prepareSession","data":{"agent":{"id":"rajat1","password":"snu6XMUjEBstKXGhLkVQ0qvnGxQ3OwddLXgfobUpK2yW1Xql-b8uAf0nlJ4q4UpFowYCUUe1_UX6qHNdy8PP5w"},"model":"RNA-PureCloud","override":true,"cti":"e70f36a4-982f-47e2-9420-780ebe581f36"}},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:34.763 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"requestId":"5b21f472-c7d2-41ae-91e2-a42813beeade","request":{"command":"prepareSession","data":{"agent":{"id":"rajat1","password":"snu6XMUjEBstKXGhLkVQ0qvnGxQ3OwddLXgfobUpK2yW1Xql-b8uAf0nlJ4q4UpFowYCUUe1_UX6qHNdy8PP5w"},"model":"RNA-PureCloud","override":true,"cti":"e70f36a4-982f-47e2-9420-780ebe581f36"}},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:34.763 UTC DEBUG PureCloudProcessor PureCloud - Looking for existing session to bind to client: PureCloud-rajat1 2023-06-13_14:58:34.763 UTC INFO PureCloudProcessor PureCloud - Creating new agent session with data {"agent":{"id":"rajat1","password":"snu6XMUjEBstKXGhLkVQ0qvnGxQ3OwddLXgfobUpK2yW1Xql-b8uAf0nlJ4q4UpFowYCUUe1_UX6qHNdy8PP5w"},"model":"RNA-PureCloud","override":true,"cti":"e70f36a4-982f-47e2-9420-780ebe581f36"}. 2023-06-13_14:58:34.765 UTC INFO WorkflowManager SYSTEM - Created new workflow session PureCloud-rajat1 with model RNA-PureCloud 2023-06-13_14:58:34.765 UTC DEBUG WorkflowManager SYSTEM - Added session com.openmethods.iserver.workflow.WorkflowSession@3e33d97a to sessions. Total sessions: 2 2023-06-13_14:58:34.765 UTC DEBUG PureCloudProcessor PureCloud - Preauthenication is not possible for PureCloud 2023-06-13_14:58:34.765 UTC INFO PureCloudProcessor PureCloud - logging in agent rajat1 with properties {"agent":{"id":"rajat1","password":"snu6XMUjEBstKXGhLkVQ0qvnGxQ3OwddLXgfobUpK2yW1Xql-b8uAf0nlJ4q4UpFowYCUUe1_UX6qHNdy8PP5w"},"model":"RNA-PureCloud","override":true,"cti":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:35.066 UTC DEBUG PureCloudAgent rajat1 - Initialized with processor com.openmethods.iserver.processor.purecloud.PureCloudProcessor@272c9f68 and ctiAgent rajat1 2023-06-13_14:58:35.066 UTC DEBUG PureCloudAgentSession PureCloud-rajat1 - initialized session for agent rajat1 2023-06-13_14:58:35.066 UTC DEBUG PureCloudAgentSession PureCloud-rajat1 - Added processor session listener com.openmethods.iserver.processor.purecloud.PureCloudProcessor@272c9f68. Total listeners: 1 2023-06-13_14:58:35.066 UTC DEBUG PureCloudProcessor PureCloud - added session PureCloud-rajat1 to {PureCloud-vishal=com.openmethods.iserver.processor.purecloud.PureCloudAgentSession@1c642be6, PureCloud-rajat1=com.openmethods.iserver.processor.purecloud.PureCloudAgentSession@56ac6195} 2023-06-13_14:58:35.066 UTC DEBUG PureCloudProcessor PureCloud - added session PureCloud-rajat1. Total sessions: 2 2023-06-13_14:58:35.066 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"serviceResponse","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","requestId":"5b21f472-c7d2-41ae-91e2-a42813beeade","response":{"command":"prepareSession","result":"success","resource":{"id":"PureCloud-rajat1"},"data":{"agent":{"id":"rajat1","password":"snu6XMUjEBstKXGhLkVQ0qvnGxQ3OwddLXgfobUpK2yW1Xql-b8uAf0nlJ4q4UpFowYCUUe1_UX6qHNdy8PP5w"},"model":"RNA-PureCloud","override":true,"cti":"e70f36a4-982f-47e2-9420-780ebe581f36"}}} 2023-06-13_14:58:35.066 UTC DEBUG WorkEngine DirectClients.5 - Item 0 done in 303 InboundMessage: {"requestId":"5b21f472-c7d2-41ae-91e2-a42813beeade","request":{"command":"prepareSession","data":{"agent":{"id":"rajat1","password":"snu6XMUjEBstKXGhLkVQ0qvnGxQ3OwddLXgfobUpK2yW1Xql-b8uAf0nlJ4q4UpFowYCUUe1_UX6qHNdy8PP5w"},"model":"RNA-PureCloud","override":true,"cti":"e70f36a4-982f-47e2-9420-780ebe581f36"}},"messageType":"serviceRequest","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36"} 2023-06-13_14:58:35.067 UTC DEBUG WorkEngine DirectClients.5 - Finished with queue processing 2023-06-13_14:58:35.067 UTC DEBUG WorkEngine DirectClients.5 - Removing queue lock for media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:35.067 UTC DEBUG WorkEngine DirectClients.5 - Going back to idle pool
The media bar retrieves information from the processor component about its capabilities (lines 1-13). It then initiates a new agent session with the processor using the “prepareSession” command (line 14). The processor starts the process of logging the agent into the telephony platform.
2023-06-13_14:58:35.176 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Request Received: {"messageType":"coreRequest","requestId":"56475f8b-a24e-4d1d-8b2c-fc9281561a45","command":"bindResource","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.176 UTC DEBUG WorkEngine DirectClients - Inspecting Queue: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound Size: 1 2023-06-13_14:58:35.176 UTC DEBUG WorkEngine DirectClients - Dequeued 1 items from media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:35.176 UTC DEBUG WorkEngine DirectClients - Looking for idle thread 2023-06-13_14:58:35.177 UTC DEBUG WorkEngine DirectClients.1 - Processing: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 1 2023-06-13_14:58:35.177 UTC DEBUG WorkEngine DirectClients.1 - Item: 0 Age: 1 InboundMessage: {"messageType":"coreRequest","requestId":"56475f8b-a24e-4d1d-8b2c-fc9281561a45","command":"bindResource","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.177 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"messageType":"coreRequest","requestId":"56475f8b-a24e-4d1d-8b2c-fc9281561a45","command":"bindResource","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.177 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"coreResponse","requestId":"56475f8b-a24e-4d1d-8b2c-fc9281561a45","command":"bindResource","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","resourceId":"PureCloud-rajat1","resourceName":"PureCloud-rajat1","resourceType":"com.openmethods.iserver.processor.session","result":"success"} 2023-06-13_14:58:35.177 UTC DEBUG WorkEngine DirectClients.1 - Item 0 done in 0 InboundMessage: {"messageType":"coreRequest","requestId":"56475f8b-a24e-4d1d-8b2c-fc9281561a45","command":"bindResource","serviceId":"e70f36a4-982f-47e2-9420-780ebe581f36","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.177 UTC DEBUG WorkEngine DirectClients.1 - Finished with queue processing 2023-06-13_14:58:35.177 UTC DEBUG WorkEngine DirectClients.1 - Removing queue lock for media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:35.177 UTC DEBUG WorkEngine DirectClients.1 - Going back to idle pool 2023-06-13_14:58:35.249 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Request Received: {"messageType":"coreRequest","requestId":"1b37e286-1d45-4e53-8d29-5ab8bdf51050","command":"bindResource","serviceId":"WorkflowManager","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.249 UTC DEBUG WorkEngine DirectClients - Inspecting Queue: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound Size: 1 2023-06-13_14:58:35.249 UTC DEBUG WorkEngine DirectClients - Dequeued 1 items from media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:35.249 UTC DEBUG WorkEngine DirectClients - Looking for idle thread 2023-06-13_14:58:35.249 UTC DEBUG WorkEngine DirectClients.2 - Processing: media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 1 2023-06-13_14:58:35.250 UTC DEBUG WorkEngine DirectClients.2 - Item: 0 Age: 0 InboundMessage: {"messageType":"coreRequest","requestId":"1b37e286-1d45-4e53-8d29-5ab8bdf51050","command":"bindResource","serviceId":"WorkflowManager","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.250 UTC DEBUG NetworkSession media-bar rajat.gupta@openmethods.com - Dispatching Message: {"messageType":"coreRequest","requestId":"1b37e286-1d45-4e53-8d29-5ab8bdf51050","command":"bindResource","serviceId":"WorkflowManager","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.250 UTC INFO View initial - Entered State: initial 2023-06-13_14:58:35.250 UTC INFO WorkflowSession PureCloud-rajat1 - Client Event: state.updated {"messageType":"stateEvent","target":"PureCloud-rajat1","name":"state.updated","context":{},"data":[{"name":"session.logout","type":"disable"},{"name":"session.login","type":"enable"}]} 2023-06-13_14:58:35.250 UTC DEBUG NetworkClient media-bar rajat.gupta@openmethods.com - Queued Response: {"messageType":"coreResponse","requestId":"1b37e286-1d45-4e53-8d29-5ab8bdf51050","command":"bindResource","serviceId":"WorkflowManager","resourceId":"PureCloud-rajat1","resourceName":"PureCloud-rajat1","resourceType":"com.openmethods.iserver.workflow.session","result":"success"} 2023-06-13_14:58:35.250 UTC DEBUG WorkEngine DirectClients.2 - Item 0 done in 1 InboundMessage: {"messageType":"coreRequest","requestId":"1b37e286-1d45-4e53-8d29-5ab8bdf51050","command":"bindResource","serviceId":"WorkflowManager","resourceId":"PureCloud-rajat1"} 2023-06-13_14:58:35.250 UTC DEBUG WorkEngine DirectClients.2 - Finished with queue processing 2023-06-13_14:58:35.250 UTC DEBUG WorkEngine DirectClients.2 - Removing queue lock for media-bar rajat.gupta@openmethods.com.9b5847bb-d944-4ac2-9eb5-ffb22b91df87.inbound 2023-06-13_14:58:35.250 UTC DEBUG WorkEngine DirectClients.2 - Going back to idle pool
As the session is created, a new processor session resource and workflow session resource are created and need to be bound to just like the processor and workflow services.
0 Comments