" /> GMS ORS Based Services not Executing - Genesys CTI User Forum

Author Topic: GMS ORS Based Services not Executing  (Read 6380 times)

Offline Maxwell

  • Newbie
  • *
  • Posts: 11
  • Karma: 0
GMS ORS Based Services not Executing
« on: April 29, 2015, 02:52:47 PM »
Advertisement
Hello,

I have recently installed and configured GMS, I am trying to test the Chat Wait option, but am getting the following error in URS:
10:44:48.168_R_I_ [19:10] routing interface request received: urs/call/start?tenant=Environment&strategy=WaitForTarget&replyurl=http%3A%2F%2F127.0.0.1%3A8080%2Fgenesys%2F1%2Fors%2Fscxml%2Fsession%2FGA26367ABP03PB2A4TCC6LRR3800000O%2Frequest%2Fmethod_urs_request_route_done&replybody=%5Btargetj%5D&replyenc=application%2Fjson&replyack=true&sync=1&TARGET=STC_Toronto_AgentGroup_PoC%40STC_RTG_STAT_SRV_51_PoC.GA&VQ_TARGET=GMS_VQ_SIP_Switch&ROUTE_DELAY=0&TARGET_TIME_TO_WAIT=300&DO_NOT_SELECT_CALL=1&MEDIA_TYPE=chat&MediaType=chat&extensiondata=&INTERACTION_AGE=undefined, client=684(HTTPINTERFACE), ref=4
10:44:48.168_R_I_ [19:10] connid 00750263a8a45004 generated for client=684(HTTPINTERFACE), ref id=4, method name=REST:
    _T_I_00750263a8a45004 [01:11] connid 00750263a8a45004 is bound to the call 4-00000000016db4a0
10:44:48.168_I_I_00750263a8a45004 [01:01] call (4-00000000016db4a0) for Environment created (del 0)
    _C_E_00750263a8a45004 [01:12] there is no strategy item for WaitForTarget
10:44:48.168_I_I_00750263a8a45004 [01:08] call (4-00000000016db4a0) deleting truly
00750263a8a45004, 04/29/15@10:44:48.168, RP(##TSERVER) -> @ [dumb  0 0], tms: 0= (N)0 + (T)0 + (X)0 + (S)0 + (W)0 + (F)0 + (R)0, trg:
10:44:48.168_R_I_ [19:12] routing interface errorresponse 'Error' sent to client=684(HTTPINTERFACE), ref=4
Message: Object not found

Offline Maxwell

  • Newbie
  • *
  • Posts: 11
  • Karma: 0
Re: GMS ORS Based Services not Executing
« Reply #1 on: April 29, 2015, 04:59:42 PM »
UPDATE: I have resolved the initial problem, by redownloading the strategy files and recomposing them (they had been corrupted at some point).

I now have the following error in GMS:

12:49:04.236 Int 09900  [qtp1999350444-162] WARNING: Failed to aggregate event: com.genesyslab.gsg.services.datadepot.model.ActivityEvent@35e81c85 com.genesyslab.gsg.services.datadepot.exceptions.PropertyNotFoundException: Aggregated property [media_type] is missing in received event: com.genesyslab.gsg.services.datadepot.model.ActivityEvent@35e81c85
com.genesyslab.gsg.services.datadepot.exceptions.PropertyNotFoundException: Aggregated property [media_type] is missing in received event: com.genesyslab.gsg.services.datadepot.model.ActivityEvent@35e81c85
      at com.genesyslab.gsg.services.datadepot.activity.ActivityEventWorker.extractAggregateProperty(ActivityEventWorker.java:161)
      at com.genesyslab.gsg.services.datadepot.activity.ActivityEventWorker.processAggregate(ActivityEventWorker.java:103)
      at com.genesyslab.gsg.services.datadepot.activity.ActivityEventWorker.processEvent(ActivityEventWorker.java:52)
      at com.genesyslab.gsg.services.datadepot.DataDepotService.processActivityEvent(DataDepotService.java:490)
      at com.genesyslab.gsg.services.datadepot.DataDepotService.processActivityEvents(DataDepotService.java:501)
      at com.genesyslab.gsg.services.datadepot.DataDepotService.processActivityEvents(DataDepotService.java:513)
      at com.genesyslab.gsg.web.controllers.DataDepotController.activityEvent(DataDepotController.java:345)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)  [native]
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:606)
      at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:219)
      at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132)
      at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
      at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:745)
      at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:686)
      at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
      at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
      at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
      at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:936)
      at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:838)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:755)
      at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:812)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)
      at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:684)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1496)
      at com.genesyslab.gsg.web.StatsFilter.handle(StatsFilter.java:59)
      at com.genesyslab.gsg.web.StatsFilter.doFilter(StatsFilter.java:42)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1467)
      at org.eclipse.jetty.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:247)
      at org.eclipse.jetty.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:210)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1467)
      at org.springframework.web.filter.AbstractRequestLoggingFilter.doFilterInternal(AbstractRequestLoggingFilter.java:213)
      at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1467)
      at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
      at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1467)
      at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:499)
      at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
      at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:533)
      at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
      at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086)
      at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:428)
      at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
      at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020)
      at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
      at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255)
      at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
      at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
      at org.eclipse.jetty.server.Server.handle(Server.java:370)
      at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:494)
      at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:982)
      at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1043)
      at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:865)
      at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
      at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
      at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:667)
      at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
      at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
      at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
      at java.lang.Thread.run(Thread.java:745)

12:49:04.244 Dbg 09900  [qtp1999350444-162] Processing aggregate: group=[com.genesyslab.gsg.services.datadepot.aggregates.model.AggregateGroup@9186d6a] name=[TotalEntered] activity=[callback]
12:49:04.244 Dbg 09900  [qtp1999350444-162] Incrementing aggregate counter: activityName=[callback] aggregateName=[TotalEntered] time=[1430326144227] incrValue=[1]
12:49:04.245 Dbg 09900  [qtp1999350444-162] Incrementing counter AggregateCounters: key=[1.callback_target_TotalEntered_STC_Toronto_AgentGroup_PoC@STC_RTG_STAT_SRV_51_PoC.GA]
12:49:04.247 Dbg 09900  [qtp1999350444-162] Processing aggregate: group=[com.genesyslab.gsg.services.datadepot.aggregates.model.AggregateGroup@3ad7686d] name=[HoldTime] activity=[callback]
12:49:04.248 Int 09900  [qtp1999350444-162] WARNING: The event for activity [callback] is missing the required dimension [media_type]
12:49:04.249 Dbg 09900  [qtp1999350444-162] WARNING: Aggregate [HoldTime] in activity [callback] has no dimmension specified. Nothing to do
12:49:04.250 Dbg 09900  [qtp1999350444-162] Processing aggregate: group=[com.genesyslab.gsg.services.datadepot.aggregates.model.AggregateGroup@3ad7686d] name=[HoldTime] activity=[callback]
12:49:04.250 Int 09900  [qtp1999350444-162] WARNING: The event for activity [callback] is missing the required dimension [media_type]
12:49:04.251 Dbg 09900  [qtp1999350444-162] WARNING: Aggregate [HoldTime] in activity [callback] has no dimmension specified. Nothing to do
12:49:04.251 Dbg 09900  [qtp1999350444-164] (POST) Client IP Address: 127.0.0.1, URI:http://127.0.0.1:8080/genesys/1/datadepot/notifications/publish
12:49:04.251 Dbg 09900  [qtp1999350444-162] Processing aggregate: group=[com.genesyslab.gsg.services.datadepot.aggregates.model.AggregateGroup@3ad7686d] name=[HoldTime] activity=[callback]
12:49:04.252 Dbg 09900  [qtp1999350444-164] Params: KVList:
12:49:04.252 Int 09900  [qtp1999350444-162] WARNING: The event for activity [callback] is missing the required dimension [media_type]
12:49:04.253 Dbg 09900  [qtp1999350444-162] WARNING: Aggregate [HoldTime] in activity [callback] has no dimmension specified. Nothing to do
12:49:04.253 Dbg 09900  [qtp1999350444-162] Activity event processed: 18ms
12:49:04.258 Dbg 09900  [qtp1999350444-164] Activity event processed: 1ms
12:49:06.877 Dbg 09900  [GMScheduler-7] Setting comet client location: user 10.180.129.62:8080@1430324726171, clientId 31ps9amlgvg4xd1vtrqk5jom6eo, location 10.180.129.62:8080@1430324726171
12:49:11.882 Dbg 09900  [GMScheduler-4] Setting comet client location: user 10.180.129.62:8080@1430324726171, clientId 31ps9amlgvg4xd1vtrqk5jom6eo, location 10.180.129.62:8080@1430324726171
12:49:16.885 Dbg 09900  [GMScheduler-20] Setting comet client location: user 10.180.129.62:8080@1430324726171, clientId 31ps9amlgvg4xd1vtrqk5jom6eo, location 10.180.129.62:8080@1430324726171
12:49:21.888 Dbg 09900  [GMScheduler-7] Setting comet client location: user 10.180.129.62:8080@1430324726171, clientId 31ps9amlgvg4xd1vtrqk5jom6eo, location 10.180.129.62:8080@1430324726171
12:49:26.891 Dbg 09900  [GMScheduler-1] Setting comet client location: user 10.180.129.62:8080@1430324726171, clientId 31ps9amlgvg4xd1vtrqk5jom6eo, location 10.180.129.62:8080@1430324726171
12:49:31.895 Dbg 09900  [GMScheduler-20] Setting comet client location: user 10.180.129.62:8080@1430324726171, clientId 31ps9amlgvg4xd1vtrqk5jom6eo, location 10.180.129.62:8080@1430324726171
12:49:34.338 Dbg 09900  [qtp1999350444-149] (POST) Client IP Address: 127.0.0.1, URI:http://127.0.0.1:8080/genesys/1/notification/publish
12:49:34.339 Dbg 09900  [qtp1999350444-149] Params: KVList:
12:49:34.349 Dbg 09900  [qtp1999350444-149] Notifying 1 subscriptions
12:49:34.350 Dbg 09900  [qtp1999350444-149] Notifying subscription Subscription [id=136-42d56522-6792-44b5-92d9-7efe32d275fd, subscriberId=136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, expiration=0, filter=service.agentavailable.136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, notificationDetails=NotificationDetails [type=comet, deviceId=jdoe_desktop, properties={debug=nodebug}], providerName=null, language=null, authorization=N]with event NotificationEvent [tag=service.agentavailable.136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, language=N/A, mediaEntry=StringMediaEntry [value={"_id":"136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02", "_action":"get-dialog-user-confirmation-provide_code-false" }], providerName=null, notificationDetails=NotificationDetails [type=null, deviceId=null, properties={apple.alertMessage.body=Agent is available. Waiting for your confirmation.}], subscriptionId=null, essential=true, authorization=N]
12:49:34.351 Dbg 09900 Notification2ProviderDispatcher dispatching NotificationDTO [notification=NotificationEvent [tag=service.agentavailable.136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, language=N/A, mediaEntry=StringMediaEntry [value={"_id":"136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02", "_action":"get-dialog-user-confirmation-provide_code-false" }], providerName=null, notificationDetails=NotificationDetails [type=null, deviceId=null, properties={apple.alertMessage.body=Agent is available. Waiting for your confirmation.}], subscriptionId=null, essential=true, authorization=N], subscription=Subscription [id=136-42d56522-6792-44b5-92d9-7efe32d275fd, subscriberId=136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, expiration=0, filter=service.agentavailable.136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, notificationDetails=NotificationDetails [type=comet, deviceId=jdoe_desktop, properties={debug=nodebug}], providerName=null, language=null, authorization=N]] to provider null
12:49:34.359 Dbg 09900  [qtp1999350444-149] result of publishing NotificationEvent [tag=service.agentavailable.136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, language=N/A, mediaEntry=StringMediaEntry [value={"_id":"136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02", "_action":"get-dialog-user-confirmation-provide_code-false" }], providerName=null, notificationDetails=NotificationDetails [type=null, deviceId=null, properties={apple.alertMessage.body=Agent is available. Waiting for your confirmation.}], subscriptionId=null, essential=true, authorization=N] : {notified=[Subscription [id=136-42d56522-6792-44b5-92d9-7efe32d275fd, subscriberId=136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, expiration=0, filter=service.agentavailable.136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, notificationDetails=NotificationDetails [type=comet, deviceId=jdoe_desktop, properties={debug=nodebug}], providerName=null, language=null, authorization=N]]}
12:49:34.361 Dbg 09900  [GMSTaskExecutor-20] Counter Incremented (notification:__notification)
12:49:34.369 Dbg 09900  [qtp1999350444-165] (GET) Client IP Address: 10.180.115.193, URI:http://stcdevmevo52.dev.can:8080/genesys/1/service/136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02/get-dialog-user-confirmation-provide_code-false
12:49:34.375 Dbg 09900  [qtp1999350444-159] (GET) Client IP Address: 10.180.115.191, URI:http://stcdevmevo52.dev.can:8080/genesys/1/service/136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02/get-dialog-user-confirmation-provide_code-false
12:49:34.389 Dbg 09900  [qtp1999350444-151] Setting comet client location: user jdoe_desktop, clientId 21a52iqvs524gixz9frqodqvk, location 10.180.129.62:8080@1430324726171
12:49:34.410 Trc 09900  [qtp1999350444-165] >>>Service specific request: [id=136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, event=get-dialog-user-confirmation-provide_code-false]
12:49:34.415 Int 09900  [qtp1999350444-165] Service with id 136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02 contains session to fetch : 2Q6GSFQHVL60V97DNRTPROHP20000002
12:49:34.416 Trc 09900  [qtp1999350444-159] >>>Service specific request: [id=136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02, event=get-dialog-user-confirmation-provide_code-false]
12:49:34.421 Int 09900  [qtp1999350444-159] Service with id 136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02 contains session to fetch : 2Q6GSFQHVL60V97DNRTPROHP20000002
12:49:34.423 Int 09900  [qtp1999350444-165] Service with id 136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02 contains session to fetch : 2Q6GSFQHVL60V97DNRTPROHP20000002
12:49:34.429 Int 09900  [qtp1999350444-159] Service with id 136-a0f8a722-5a8b-4324-bd10-b65b91d2ae02 contains session to fetch : 2Q6GSFQHVL60V97DNRTPROHP20000002
12:49:34.443 Dbg 09900  [qtp1999350444-165] Cookie retrieved from storage for the session='2Q6GSFQHVL60V97DNRTPROHP20000002' is [version: 0][name: ORSSESSIONID][value: 2Q6GSFQHVL60V97DNRTPROHP20000002.node118][domain: 10.180.129.62][path: /scxml/session][expiry: null]
12:49:34.444 Dbg 09900  [qtp1999350444-165] Sending request to /scxml/session/2Q6GSFQHVL60V97DNRTPROHP20000002/request/get-dialog-user-confirmation-provide_code-false
12:49:34.445 Trc 09900  [qtp1999350444-165] OrsService: submit to ORS http://10.180.129.62:3801/scxml/session/2Q6GSFQHVL60V97DNRTPROHP20000002/request/get-dialog-user-confirmation-provide_code-false
12:49:34.448 Dbg 09900  [qtp1999350444-159] Cookie retrieved from storage for the session='2Q6GSFQHVL60V97DNRTPROHP20000002' is [version: 0][name: ORSSESSIONID][value: 2Q6GSFQHVL60V97DNRTPROHP20000002.node118][domain: 10.180.129.62][path: /scxml/session][expiry: null]
12:49:34.449 Dbg 09900  [qtp1999350444-159] Sending request to /scxml/session/2Q6GSFQHVL60V97DNRTPROHP20000002/request/get-dialog-user-confirmation-provide_code-false
12:49:34.450 Trc 09900  [qtp1999350444-159] OrsService: submit to ORS http://10.180.129.62:3801/scxml/session/2Q6GSFQHVL60V97DNRTPROHP20000002/request/get-dialog-user-confirmation-provide_code-false
12:49:34.471 Dbg 09900  [qtp1999350444-149] (POST) Client IP Address: 127.0.0.1, URI:http://127.0.0.1:8080/genesys/1/datadepot/notifications/publish
12:49:34.472 Dbg 09900  [qtp1999350444-149] Params: KVList:
12:49:34.480 Trc 09900  [qtp1999350444-165] OrsService: response from ORS KVList:


Offline cavagnaro

  • Administrator
  • Hero Member
  • *****
  • Posts: 7641
  • Karma: 56330
Re: GMS ORS Based Services not Executing
« Reply #2 on: April 29, 2015, 05:52:29 PM »
Well...a data "media_type" (voice, chat, etc) is missing...

Offline Maxwell

  • Newbie
  • *
  • Posts: 11
  • Karma: 0
Re: GMS ORS Based Services not Executing
« Reply #3 on: April 29, 2015, 07:15:14 PM »
Hi Cavagnaro,

Thank you for your response, but the issue we are having is addressing that error. We are all in agreement that something should populate - it is showing as chat in Stat Server, but now making it to GMS

Offline cavagnaro

  • Administrator
  • Hero Member
  • *****
  • Posts: 7641
  • Karma: 56330
Re: GMS ORS Based Services not Executing
« Reply #4 on: April 29, 2015, 07:37:54 PM »
For what I see it processes StatServer options, like HoldTime, maybe add the MediaType property to it?

Offline Maxwell

  • Newbie
  • *
  • Posts: 11
  • Karma: 0
Re: GMS ORS Based Services not Executing
« Reply #5 on: April 30, 2015, 05:43:57 PM »
I ended up creating my own service and it reads the media type fine, this option _media_type is set in the GMS service. Now it is stuck at the routing stage (EventQueued). Anyone with experience in routing able to help?

URS log:

request to 65201(--) message RequestDistributeEvent
AttributeMediaType 5
AttributeTimeout 60
AttributeTimeinuSecs 315000
AttributeTimeinSecs 1430415059 (13:30:59)
AttributeExtensions [184] 00 06 00 00..
'SIGNATURE' 'router'
'NAME' 'STC_RTG_UR_SRV_51_PoC'
'VERSION' 'Version: 8.1.400.06'
'CLUSTER' 'STC_RTG_UR_SRV_51_PoC'
'VQID' 'Q36SPA4FKD7FV2184UTNGLBH3S000004'
'CUSTOMER_ID' 'Environment'
AttributeUserData [59] 00 02 00 00..
'GMS_ROUTABLE' '0'
'RouterData70' '("t"="1430415059 312")'
AttributeOtherDNRole 1
AttributeThisDNRole 2
AttributeThisQueue 'MobilePoC'
AttributeThisDN 'MobilePoC'
AttributeConnID 00750263bfbf4005
AttributeCustomerID 'Environment'
AttributeReferenceID 4294967295
AttributeUserEvent EventQueued
..sent to stcdevxmevo51.x.dev.can:16130(fd=672)
13:30:59.315_M_I_00750263bfbf4005 [13:02] entering vq "MobilePoC"
    _M_I_00750263bfbf4005 [17:0f] VQ 0000000001a9bb30 [at all 2 0 0] 1 Target(s), flag=c08a, guid: 0Environment|MobilePoC|1|md38|1|00|0||||||00|00{}{}{}[]STC_Toronto_AgentGroup_PoC@STC_RTG_STAT_SRV_51_PoC.GA
13:30:59.315_M_I_00750263bfbf4005 [13:01] current vq: 0000000001a35a90 id=5(), nVQ=1-1a06170, priority=0, time=1430415059.312
13:30:59.315_M_I_00750263bfbf4005 [13:03] call (vq 0000000001a35a90, id=5, priority 0, time 1430415059.312) waits for VQ 0000000001a9bb30 (name="MobilePoC") now (0)
    _T_I_00750263bfbf4005 [0E:19] check call routing states: s=0 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _I_I_00750263bfbf4005 [07:0a] HERE IS WAIT (-1 sec)
    _I_I_00750263bfbf4005 [07:0a] HERE IS WAIT (300 sec)
13:30:59.315_B_I_00750263bfbf4005 [07:0a] delay treatments for 0 msec
13:30:59.315_I_I_00750263bfbf4005 [09:04] <<<<<<<<<<<<suspend interp(WAIT), func:Wait timers:11000
13:30:59.315_B_I_00750263bfbf4005 [07:64] start chain of treatments
received from 65201(STC_ESRV_IXN_SRV_51_PoC)stcdevxmevo51.x.dev.can:16130(fd=) message EventACK(refid=-1)
13:30:59.386_R_I_ [19:10] routing interface request received: urs/call/00750263bfbf4005/func?name=FindConfigObject&params=%5B2,%20%22name:MobilePoC%22%5D, client=656(HTTPINTERFACE), ref=21
13:30:59.386_I_I_00750263bfbf4005 [09:06] >>>>>>>>>>>>start interp()
    _I_I_00750263bfbf4005 [07:46] no error mode for this call
    _I_I_00750263bfbf4005 [09:04] ASSIGN: v:0:this(LOCAL) <- OBJECT:000000000115EF70[Global]={"Class":"Global"}
    _I_I_00750263bfbf4005 [09:04] ASSIGN: v:0:_urs(LOCAL) <- OBJECT:0000000001A35BB0[FM]={}
    _I_I_00750263bfbf4005 [09:04] ASSIGN: v:0:_parms(LOCAL) <- OBJECT:0000000001A35A30[Array]=[2,"name:MobilePoC"]
    _I_I_00750263bfbf4005 [09:04] ASSIGN: v:0:_func(LOCAL) <- STRING: "FindConfigObject"
    _I_I_00750263bfbf4005 [09:04] ASSIGN: v:0:_r(LOCAL) <- LIST: dbid:134|type:5|number:MobilePoC|name:MobilePoC|switchdbid:102|switch:STC_ESRV_MM_SWITCH_51_PoC|tenantdbid:1|tenant:Environment|annex.:
    _I_I_00750263bfbf4005 [01:1f] <<<<<<<<<<<<stop interp
13:30:59.386_R_I_ [19:11] routing interface response 'Info' sent to client=656(HTTPINTERFACE), ref=21
Message: {"dbid":134,"type":5,"number":"MobilePoC","name":"MobilePoC","switchdbid":102,"switch":"STC_ESRV_MM_SWITCH_51_PoC","tenantdbid":1,"tenant":"Environment","annex":{}}
13:30:59.452_R_I_ [19:10] routing interface request received: urs/call/00750263bfbf4005/udata?RouterData70, client=656(HTTPINTERFACE), ref=22
13:30:59.452_R_I_ [19:11] routing interface response 'Info' sent to client=656(HTTPINTERFACE), ref=22
Message: {"RouterData70":"(\"t\"=\"1430415059 312\")"}
13:30:59.514_R_I_ [19:10] routing interface request received: urs/call/00750263bfbf4005/lvq?name=MobilePoC&aqt=stat&filter=ewt%2Ctime%2Cwt%2Ccalls%2Cpos%2Cwpos%2Chit, client=656(HTTPINTERFACE), ref=23
13:30:59.514_R_I_ [19:11] routing interface response 'Info' sent to client=656(HTTPINTERFACE), ref=23
Message: {"time":1430415059,"wt":0,"calls":1,"pos":1,"wpos":1,"ewt":10000,"hit":0}
13:31:00.000_M_I_ [10:1d] PULSE (calls: 2(2)=1+1-0, targets=1, firsters=0, time=1430415060, mem=0,17254,102,21,181,0,2,0)
13:31:00.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:00.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 3 missed 2 next
13:31:02.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415062, mem=0,17254,102,21,181,0,2,0)
13:31:02.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:02.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 4 missed 2 next
13:31:03.496_G_I_ [01:0b] look for hanged interactions: 2 at all now (1 cpu usage)
13:31:03.496_G_I_ [01:0b] there are 2 calls in progress now
_G_I_ Version: 8.1.400.06
root 0000000040bc7200 (4,4,8)
thread 0000000000001ce0
13:31:03.653 Trc 20011 current number of targets for tenant Environment: Agents 11, Places 0, AgentGroups 1, PlaceGroups 0, ACDQueues 0, Routing Points 0
13:31:03.653 Trc 20012 current number of interactions per second - 0.20
13:31:03.653 Trc 20013 current number of entries: for longest queue 0, for all queues 0
13:31:04.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415064, mem=0,17254,102,21,181,0,2,0)
13:31:04.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:04.000_M_I_ [10:1d] check queue for SO <002> type <Agent> stat <##state> (2 trgs 0 cpu)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _M_I_ [10:0b] ag 002, pl STC_8002_Toronto_Poc, sw  dn  isn't blocked absolutely(0)
    _M_I_00750263bfbf4004 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _T_I_00750263bfbf4004 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4004 [10:21] state of call isn't good for routing
    _M_I_00750263bfbf4005 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _T_I_00750263bfbf4005 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4005 [10:21] state of call isn't good for routing
13:31:04.000_M_I_ [10:1d] PULSE over: 0 cpu 1 objects 2 trgs
13:31:06.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415066, mem=0,17254,102,21,181,0,2,0)
13:31:06.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:06.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 1 missed 2 next
13:31:08.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415068, mem=0,17254,102,21,181,0,2,0)
13:31:08.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:08.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 2 missed 2 next
13:31:10.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415070, mem=0,17254,102,21,181,0,2,0)
13:31:10.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:10.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 3 missed 2 next
13:31:12.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415072, mem=0,17254,102,21,181,0,2,0)
13:31:12.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:12.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 4 missed 2 next
13:31:14.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415074, mem=0,17254,102,21,181,0,2,0)
13:31:14.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:14.000_M_I_ [10:1d] check queue for SO <002> type <Agent> stat <##state> (2 trgs 0 cpu)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _M_I_ [10:0b] ag 002, pl STC_8002_Toronto_Poc, sw  dn  isn't blocked absolutely(0)
    _M_I_00750263bfbf4004 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _T_I_00750263bfbf4004 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4004 [10:21] state of call isn't good for routing
    _M_I_00750263bfbf4005 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _T_I_00750263bfbf4005 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4005 [10:21] state of call isn't good for routing
13:31:14.000_M_I_ [10:1d] PULSE over: 0 cpu 1 objects 2 trgs
13:31:16.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415076, mem=0,17254,102,21,181,0,2,0)
13:31:16.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:16.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 1 missed 2 next
13:31:18.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415078, mem=0,17254,102,21,181,0,2,0)
13:31:18.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:18.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 2 missed 2 next
13:31:20.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415080, mem=0,17254,102,21,181,0,2,0)
13:31:20.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:20.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 3 missed 2 next
13:31:22.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415082, mem=0,17254,102,21,181,0,2,0)
13:31:22.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:22.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 4 missed 2 next
13:31:24.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415084, mem=0,17254,102,21,181,0,2,0)
13:31:24.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:24.000_M_I_ [10:1d] check queue for SO <002> type <Agent> stat <##state> (2 trgs 0 cpu)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _M_I_ [10:0b] ag 002, pl STC_8002_Toronto_Poc, sw  dn  isn't blocked absolutely(0)
    _M_I_00750263bfbf4004 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _T_I_00750263bfbf4004 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4004 [10:21] state of call isn't good for routing
    _M_I_00750263bfbf4005 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _T_I_00750263bfbf4005 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4005 [10:21] state of call isn't good for routing
13:31:24.000_M_I_ [10:1d] PULSE over: 0 cpu 1 objects 2 trgs
13:31:26.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415086, mem=0,17254,102,21,181,0,2,0)
13:31:26.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:26.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 1 missed 2 next
13:31:28.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415088, mem=0,17254,102,21,181,0,2,0)
13:31:28.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:28.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 2 missed 2 next
13:31:30.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415090, mem=0,17254,102,21,181,0,2,0)
13:31:30.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:30.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 3 missed 2 next
13:31:32.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415092, mem=0,17254,102,21,181,0,2,0)
13:31:32.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:32.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 4 missed 2 next
13:31:34.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415094, mem=0,17254,102,21,181,0,2,0)
13:31:34.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:34.000_M_I_ [10:1d] check queue for SO <002> type <Agent> stat <##state> (2 trgs 0 cpu)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _M_I_ [10:0b] ag 002, pl STC_8002_Toronto_Poc, sw  dn  isn't blocked absolutely(0)
    _M_I_00750263bfbf4004 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _T_I_00750263bfbf4004 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4004 [10:21] state of call isn't good for routing
    _M_I_00750263bfbf4005 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _T_I_00750263bfbf4005 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4005 [10:21] state of call isn't good for routing
13:31:34.000_M_I_ [10:1d] PULSE over: 0 cpu 1 objects 2 trgs
13:31:36.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415096, mem=0,17254,102,21,181,0,2,0)
13:31:36.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:36.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 1 missed 2 next
13:31:38.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415098, mem=0,17254,102,21,181,0,2,0)
13:31:38.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:38.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 2 missed 2 next
13:31:40.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415100, mem=0,17254,102,21,181,0,2,0)
13:31:40.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:40.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 3 missed 2 next
13:31:42.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415102, mem=0,17254,102,21,181,0,2,0)
13:31:42.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:42.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 4 missed 2 next
13:31:44.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415104, mem=0,17254,102,21,181,0,2,0)
13:31:44.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:44.001_M_I_ [10:1d] check queue for SO <002> type <Agent> stat <##state> (2 trgs 0 cpu)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _M_I_ [10:0b] ag 002, pl STC_8002_Toronto_Poc, sw  dn  isn't blocked absolutely(0)
    _M_I_00750263bfbf4004 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _T_I_00750263bfbf4004 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4004 [10:21] state of call isn't good for routing
    _M_I_00750263bfbf4005 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _T_I_00750263bfbf4005 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4005 [10:21] state of call isn't good for routing
13:31:44.001_M_I_ [10:1d] PULSE over: 0 cpu 1 objects 2 trgs
13:31:46.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415106, mem=0,17254,102,21,181,0,2,0)
13:31:46.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:46.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 1 missed 2 next
13:31:48.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415108, mem=0,17254,102,21,181,0,2,0)
13:31:48.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:48.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 2 missed 2 next
13:31:50.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415110, mem=0,17254,102,21,181,0,2,0)
13:31:50.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:50.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 3 missed 2 next
13:31:52.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415112, mem=0,17254,102,21,181,0,2,0)
13:31:52.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:52.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 4 missed 2 next
13:31:54.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415114, mem=0,17254,102,21,181,0,2,0)
13:31:54.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:54.001_M_I_ [10:1d] check queue for SO <002> type <Agent> stat <##state> (2 trgs 0 cpu)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _M_I_0000000000000000 [10:20] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _M_I_ [10:0b] ag 002, pl STC_8002_Toronto_Poc, sw  dn  isn't blocked absolutely(0)
    _M_I_00750263bfbf4004 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822d30 VQ 0000000001a9bc50(1 calls)
    _T_I_00750263bfbf4004 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4004 [10:21] state of call isn't good for routing
    _M_I_00750263bfbf4005 [10:21] try to route to ag "002" (pl "STC_8002_Toronto_Poc", 1 ready DNs, 2 trgs): TRG 0000000001822910 VQ 0000000001a9bb30(1 calls)
    _T_I_00750263bfbf4005 [0E:19] check call routing states: s=4 d=0 t=0 h=(0 0) r=0 i=0 x=0 b=1 - false
    _M_I_00750263bfbf4005 [10:21] state of call isn't good for routing
13:31:54.001_M_I_ [10:1d] PULSE over: 0 cpu 1 objects 2 trgs
13:31:56.000_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415116, mem=0,17254,102,21,181,0,2,0)
13:31:56.000_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:56.000_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 1 missed 2 next
13:31:58.001_M_I_ [10:1d] PULSE (calls: 2(2)=2+0-0, targets=1, firsters=0, time=1430415118, mem=0,17254,102,21,181,0,2,0)
13:31:58.001_M_I_ [10:1d] vqs allocation pattern: static=(13 256 128) dynamic=(5 5/1024)
13:31:58.001_M_I_ [10:1d] PULSE no calls, skipped: 0 cpu 2 missed 2 next
13:31:59.315_T_I_00750263bfbf4005 [14:02] sending event 154 for vq MobilePoC (0 0 0 0 0 0)