Konami transfer almost working

[Mikko]

Hi,

I’ve got konami transfer working to the point that the konami application receives the transfer message. After that nothing happens :(
Please give me some advice on how I can debug the problem further or am I even on the right track to getting it working.

Here is what I have done to get to this point:
1.    I was missing the metaflow exchange, so I created one.
rabbitmqadmin declare exchange name=metaflow type=topic
2.    Made sure konami is running.
sup kapps_controller running_apps
3.    Added default metaflow for account
sup kapps_account_config set XXXXX metaflows default_metaflow true
3.    Added route_key for metaflow.action messages
rabbitmqadmin declare binding source="metaflow" destination_type="queue" destination="konami_listener" routing_key="metaflow.action.*.*"
4.    Wrote a script that queries the channels and initiates a transfer by POST to kazoo port 8000.


Our kazoo version is GIT 4.0.0 up to commit dd5a223acb0f0832c362bc1db44f4c5fe57961ed (Feb 5 2017)

Here is what my rabbitmq bindings look like for the konami_listener:
+-----------------+-------------------------------------+----------------------+
|     source      |             destination             |      routing_key     |
+-----------------+-------------------------------------+----------------------+
|                 | konami_listener                     | konami_listener      |
| callmgr         | konami_listener                     | route.req.*.*        |
| callmgr         | konami_listener                     | route.req.*.*.*      |
| metaflow        | konami_listener                     | metaflow.action.*.*  |
| metaflow        | konami_listener                     | metaflow.bind.*.*    |
+-----------------+-------------------------------------+----------------------+

Here is the status info I get back from the transfer POST.
  "data": "transfer initiated",
  "revision": "undefined",
  "request_id": "72c40fb078e4ae768e5b53d91460899f",
  "status": "success",
  "auth_token": "..."

Here are the outbound and inbound calls for the test:
Account ACCOUNT call-ids
        uuid = 2259313c-d46a-4f92-8e53-7303d22a6952
        destination = "00456789"
        direction = "outbound"
        is_loopback = false

        uuid = 0000265500002510000062ed00001f03@SBC_IN
        destination = "+3589123456"
        direction = "inbound"
        is_loopback = false

The transfer target is +3589999999.


Here is the trace from rabbitmq’s metaflow-exchange:
================================================================================
2017-04-25 19:53:33:683: Message published
Node:         kazoo-rabbit@kazoo
Connection:   127.0.0.1:44881 -> 127.0.0.1:5672
Virtual host: /
User:         guest
Channel:      136
Exchange:     metaflow
Routing keys: [<<"metaflow.bind.100000000001.21147deb-d0a5-48e0-802f-64ea2f8c7ff4">>]
Routed queues: [<<"konami_listener">>]
Properties:   [{<<"content_type">>,longstr,<<"application/json">>}]
Payload:
{"Listen-On":"self","Endpoint-ID":"c7977a34493ff042b898cf74e32f2d94","Binding-Digit":"*","Patterns":{"2(\\d+)":{"module":"transfer","data":{"takeback_dtmf":"*1"}}},"Call-ID":"21147deb-d0a5-48e0-802f-64ea2f8c7ff4","Call":{"Key-Value-Store":{"cf_capture_groups":{},"cf_flow":{"children":{},"data":{"caller_id_type":"external","custom_sip_headers":{},"ignore_early_media":false,"use_local_resources":true},"module":"offnet"},"cf_flow_id":"ef3dc6fc6829f868dabb2094057ad412","cf_metaflow":"true","cf_no_match":true,"owner_id":"b27257e420981374d1f81671cfa39a0b"},"Call-ID":"21147deb-d0a5-48e0-802f-64ea2f8c7ff4","Control-Queue":"kazoo...@kazoo.DOMAIN-<0.10098.994>-31405ce3","Controller-Queue":"kazoo...@kazoo.DOMAIN-<0.1472.0>-1a8a6dbd","Caller-ID-Name":"3587777777","Caller-ID-Number":"+3589123456","Callee-ID-Number":"00456789","Request":"0045...@nodomain.com","Request-User":"00456789","Request-Realm":"nodomain.com","From":"10...@ACCOUNT.DOMAIN","From-User":"1000","From-Realm":"ACCOUNT.DOMAIN","To":"0045...@nodomain.com","To-User":"00456789","To-Realm":"nodomain.com","Switch-Hostname":"FS1HOSTNAME.DOMAIN","Switch-Nodename":"freeswitch@FREESWITCH1-INT","Switch-URL":"sip:mod_sofia@FREESWITCH1:11000","Switch-URI":"sip:FREESWITCH1:11000","Inception":"+3589123456@SBC1","Account-DB":"account%2F10%2F64%20000002","Account-ID":"100000000001","Authorizing-ID":"c7977a34493ff042b898cf74e32f2d94","Authorizing-Type":"device","Owner-ID":"b27257e420981374d1f81671cfa39a0b","Fetch-ID":"22067b2f-8108-4bd8-891d-31cddbff3730","Bridge-ID":"0000404900006a4200001a8b00006f04@SBC_IN","Custom-Channel-Vars":{"Call-Interaction-ID":"63660369212-5d50373c","Fetch-ID":"22067b2f-8108-4bd8-891d-31cddbff3730","Account-ID":"100000000001","Authorizing-ID":"c7977a34493ff042b898cf74e32f2d94","Authorizing-Type":"device","Bridge-ID":"0000404900006a4200001a8b00006f04@SBC_IN","Call-Forward":"true","Ecallmgr-Node":"kazoo...@kazoo.DOMAIN","Inception":"+3589123456@SBC1","Owner-ID":"b27257e420981374d1f81671cfa39a0b","Caller-Screen-Bit":true,"Caller-Privacy-Hide-Name":false,"Caller-Privacy-Hide-Number":false,"CallFlow-ID":"ef3dc6fc6829f868dabb2094057ad412","Application-Node":"kazoo...@kazoo.DOMAIN","Application-Name":"callflow","Caller-ID-Number":"+3589123456","Caller-ID-Name":"3587777777"},"Custom-SIP-Headers":{},"Resource-Type":"audio","Language":"en-us","Call-Direction":"inbound"},"Node":"kazoo...@kazoo.DOMAIN","Account-ID":"100000000001","Msg-ID":"585d1a1212b8ae1b","Event-Name":"bind","Event-Category":"metaflow","App-Version":"4.0.0","App-Name":"kazoo_endpoint"}

================================================================================
2017-04-25 19:54:09:281: Message published
Node:         kazoo-rabbit@kazoo
Connection:   127.0.0.1:44881 -> 127.0.0.1:5672
Virtual host: /
User:         guest
Channel:      131
Exchange:     metaflow
Routing keys: [<<"metaflow.bind.100000000001.5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>]
Routed queues: [<<"konami_listener">>]
Properties:   [{<<"content_type">>,longstr,<<"application/json">>}]
Payload:
{"Listen-On":"self","Endpoint-ID":"c7977a34493ff042b898cf74e32f2d94","Binding-Digit":"*","Patterns":{"2(\\d+)":{"module":"transfer","data":{"takeback_dtmf":"*1"}}},"Call-ID":"5e16a86d-e0ed-4e24-a51f-fca799fa49e2","Call":{"Key-Value-Store":{"cf_capture_groups":{},"cf_flow":{"children":{},"data":{"caller_id_type":"external","custom_sip_headers":{},"ignore_early_media":false,"use_local_resources":true},"module":"offnet"},"cf_flow_id":"ef3dc6fc6829f868dabb2094057ad412","cf_metaflow":"true","cf_no_match":true,"owner_id":"b27257e420981374d1f81671cfa39a0b"},"Call-ID":"5e16a86d-e0ed-4e24-a51f-fca799fa49e2","Control-Queue":"kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7","Controller-Queue":"kazoo...@kazoo.DOMAIN-<0.1472.0>-1a8a6dbd","Caller-ID-Name":"3587777777","Caller-ID-Number":"+3589123456","Callee-ID-Number":"00456789","Request":"0045...@nodomain.com","Request-User":"00456789","Request-Realm":"nodomain.com","From":"10...@ACCOUNT.DOMAIN","From-User":"1000","From-Realm":"ACCOUNT.DOMAIN","To":"0045...@nodomain.com","To-User":"00456789","To-Realm":"nodomain.com","Switch-Hostname":"FS1HOSTNAME.DOMAIN","Switch-Nodename":"freeswitch@FREESWITCH1-INT","Switch-URL":"sip:mod_sofia@FREESWITCH1:11000","Switch-URI":"sip:FREESWITCH1:11000","Inception":"+3589123456@SBC1","Account-DB":"account%2F10%2F64%20000002","Account-ID":"100000000001","Authorizing-ID":"c7977a34493ff042b898cf74e32f2d94","Authorizing-Type":"device","Owner-ID":"b27257e420981374d1f81671cfa39a0b","Fetch-ID":"c4243acd-feae-463c-aa70-123a2fbbd19d","Bridge-ID":"0000265500002510000062ed00001f03@SBC_IN","Custom-Channel-Vars":{"Call-Interaction-ID":"63660369248-5320e328","Fetch-ID":"c4243acd-feae-463c-aa70-123a2fbbd19d","Account-ID":"100000000001","Authorizing-ID":"c7977a34493ff042b898cf74e32f2d94","Authorizing-Type":"device","Bridge-ID":"0000265500002510000062ed00001f03@SBC_IN","Call-Forward":"true","Ecallmgr-Node":"kazoo...@kazoo.DOMAIN","Inception":"+3589123456@SBC1","Owner-ID":"b27257e420981374d1f81671cfa39a0b","Caller-Screen-Bit":true,"Caller-Privacy-Hide-Name":false,"Caller-Privacy-Hide-Number":false,"CallFlow-ID":"ef3dc6fc6829f868dabb2094057ad412","Application-Node":"kazoo...@kazoo.DOMAIN","Application-Name":"callflow","Caller-ID-Number":"+3589123456","Caller-ID-Name":"3587777777"},"Custom-SIP-Headers":{},"Resource-Type":"audio","Language":"en-us","Call-Direction":"inbound"},"Node":"kazoo...@kazoo.DOMAIN","Account-ID":"100000000001","Msg-ID":"e4872667efe8cec2","Event-Name":"bind","Event-Category":"metaflow","App-Version":"4.0.0","App-Name":"kazoo_endpoint"}

================================================================================
2017-04-25 19:54:21:742: Message published
Node:         kazoo-rabbit@kazoo
Connection:   127.0.0.1:44881 -> 127.0.0.1:5672
Virtual host: /
User:         guest
Channel:      131
Exchange:     metaflow
Routing keys: [<<"metaflow.action.0000265500002510000062ed00001f03%40SBC_IN.transfer">>]
Routed queues: [<<"konami_listener">>]
Properties:   [{<<"content_type">>,longstr,<<"application/json">>}]
Payload:
{"Data":{"target":"+3589999999","Transfer-Type":"blind"},"Call-ID":"0000265500002510000062ed00001f03@SBC_IN","Action":"transfer","Node":"kazoo...@kazoo.DOMAIN","Msg-ID":"b2320f579742d48f","Event-Name":"action","Event-Category":"metaflow","App-Version":"4.0.0","App-Name":"crossbar"}


Last but not least, kazoo’s debug log: (the rabbitmq trace and these debug lines are from the same test, the trace has UTC time and timestamp is +-30 sec)
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.12615.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.12615.994>) publishing call event channel_create
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_CREATE.0000265500002510000062ed00001f03%40SBC_IN) via <0.925.0>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.907.0>) published message 1493150048702441 for <0.12615.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_hooks_util:215 (<0.24086.994>) event 'channel_create' had no account id
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_hooks_util:220 (<0.24086.994>) determined account id for 'channel_create' is 100000000001
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_presence_amqp:198 (<0.13147.990>) received channel create, checking for presence subscribers
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_presence_amqp:319 (<0.13147.990>) no presence subscriptions for +3587777777@SBC_IN
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:29 (<0.17260.994>) evt CHANNEL_CREATE for 100000000001
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_dialog_amqp:197 (<0.13188.990>) received channel create, checking for dialog subscribers
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:31 (<0.17260.994>) no hooks to handle CHANNEL_CREATE for 100000000001
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_config:386 (<0.13188.990>) setting default for omnipresence [<<"broadcast_presence">>,<<"early">>]: undefined
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_dialog_amqp:370 (<0.13188.990>) no dialog subscriptions for +3587777777@SBC_IN
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|kz_amqp_channel:159 (<0.1718.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1743.0>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_authz:104 (<0.4790.994>) config ecallmgr.authz is disabled
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_authz:236 (<0.4790.994>) channel authorization succeeded, allowing call
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.8657.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:08 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:816 (<0.1724.0>) storing {authz_response,<<"0000265500002510000062ed00001f03@SBC_IN">>} for 3600s
Apr 25 22:54:08 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:818 (<0.1724.0>) inserted {authz_response,<<"0000265500002510000062ed00001f03@SBC_IN">>}
Apr 25 22:54:08 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:820 (<0.1724.0>) inserted origin pointers for {authz_response,<<"0000265500002510000062ed00001f03@SBC_IN">>}
Apr 25 22:54:08 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:822 (<0.1724.0>) exec store callbacks
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_authz:34 (<0.4790.994>) channel is authorized
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.907.0>) published to callmgr(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key route.req.audio.SBC_IN.%2B3587777777) via <0.925.0>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:586 (<0.907.0>) published request with msg id c9693fc7-54a2-42e1-b799-b79faf575780 for <0.8657.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|reg_authn_req:280 (<0.15296.994>) looking up IP: SBC1 in db sip_auth
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|reg_route_req:49 (<0.15296.994>) failed to find account information from IP SBC1, not replaying route req
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|konami_listener:107 (<0.21553.994>) no account id for undefined(undefined) owned by undefined
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|stepswitch_inbound:45 (<0.13025.990>) running routines for number +3589123456, fetch-id : c9693fc7-54a2-42e1-b799-b79faf575780
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|stepswitch_inbound:280 (<0.13025.990>) not blacklisted undefined
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.13025.990>) published to callmgr(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key route.req.audio.100000000001) via <0.2069.0>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|stepswitch_inbound:244 (<0.13025.990>) relaying route request c9693fc7-54a2-42e1-b799-b79faf575780
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|reorder_route_req:21 (<0.6701.994>) received route request with no account-id
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_config:386 (<0.6701.994>) setting default for reorder [<<"assume_inbound_e164">>]: undefined
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|reorder_route_req:46 (<0.6701.994>) converted number to e164: +3589123456
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|reorder_route_req:58 (<0.6701.994>) sending known number response: 686 PEBCAK
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.6701.994>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.907.0>-46457d46) via <0.2051.0>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|milliwatt_route_req:37 (<0.309.994>) milliwatt does not know what to do with this!
Apr 25 22:54:08 kazoo 2600hz[1307]: |c9693fc7-54a2-42e1-b799-b79faf575780|kz_amqp_worker:749 (<0.907.0>) deferred response for msg id c9693fc7-54a2-42e1-b799-b79faf575780, waiting for primary response
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|milliwatt_route_req:37 (<0.24811.994>) milliwatt does not know what to do with this!
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_req:35 (<0.21625.994>) received request c9693fc7-54a2-42e1-b799-b79faf575780 asking if callflows can route this call
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_req:65 (<0.21625.994>) ignore preflow, not set
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_req:93 (<0.21625.994>) callflow da56fd0beb3d9360edcaa6f68f0a27c3 in 100000000001 satisfies request
Apr 25 22:54:08 kazoo 2600hz[1307]: |00000000000|kz_token_bucket:203 (<0.4738.994>) consumed 5, 95 left
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_req:196 (<0.21625.994>) callflows knows how to route the call! sending park response
Apr 25 22:54:08 kazoo 2600hz[1307]: |c9693fc7-54a2-42e1-b799-b79faf575780|kz_amqp_channel:159 (<0.964.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.907.0>-46457d46) via <0.953.0>
Apr 25 22:54:08 kazoo 2600hz[1307]: |c9693fc7-54a2-42e1-b799-b79faf575780|kz_amqp_worker:586 (<0.964.0>) published request with msg id 0000265500002510000062ed00001f03@SBC_IN for <0.21625.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ts_route_req:26 (<0.22689.994>) received request c9693fc7-54a2-42e1-b799-b79faf575780 asking if trunkstore can route this call
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ts_route_req:33 (<0.22689.994>) call with fetch-id c9693fc7-54a2-42e1-b799-b79faf575780 began from outside the network
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.2269.0>) Supervisor ts_offnet_sup started ts_from_offnet:start_link({[{<<"Caller-ID-Number">>,<<"+3587777777">>},{<<"Caller-ID-Name">>,<<"+3587777777">>},{<<"...">>,...},...]}) at pid <0.6914.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ts_callflow:68 (<0.6914.994>) using worker <0.959.0>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ts_from_offnet:269 (<0.6914.994>) building endpoint for account id 100000000001 with force out true
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|konami_listener:115 (<0.14233.994>) unhandled channel for account 100000000001: undefined(resource) owned by undefined
Apr 25 22:54:08 kazoo 2600hz[1307]: |c9693fc7-54a2-42e1-b799-b79faf575780|kz_amqp_worker:745 (<0.907.0>) response for msg id c9693fc7-54a2-42e1-b799-b79faf575780 took 15458 micro to return
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_router_util:94 (<0.8657.994>) received affirmative route response for request c9693fc7-54a2-42e1-b799-b79faf575780
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_router_util:96 (<0.8657.994>) sending XML to freeswitch@FREESWITCH1-INT: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|kazoo...@kazoo.DOMAIN won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=kazoo...@kazoo.DOMAIN"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}" inline="true"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="kz_multiset" data="^^|ecallmgr_Call-Interaction-ID=63660369248-5320e328|ecallmgr_Fetch-ID=c9693fc7-54a2-42e1-b799-b79faf575780|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Account-ID=100000000001|ignore_display_updates=true|ecallmgr_Inception=+3589123456@SBC1|ecallmgr_Authorizing-Type=resource|ecallmgr_Global-Resource=true|ecallmgr_Resource-ID=XXX-carrier|ecallmgr_Resource-Fax-Option=true|ecallmgr_CallFlow-ID=da56fd0beb3d9360edcaa6f68f0a27c3"/><action application="multiunset" data="^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT"/><action application="park"/></condition></extension></context></section></document>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ts_util:114 (<0.6914.994>) cache miss for +3589123456, no results
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ts_from_offnet:316 (<0.6914.994>) DID +3589123456 not found in 100000000001
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ts_from_offnet:43 (<0.6914.994>) call was not for a trunkstore number
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_router_util:100 (<0.8657.994>) node freeswitch@FREESWITCH1-INT accepted dialplan route response for request c9693fc7-54a2-42e1-b799-b79faf575780
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_event_sup:38 (<0.8657.994>) starting event handler for freeswitch@FREESWITCH1-INT
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.15179.994>) starting new gen_listener proc : ecallmgr_call_events
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:189 (<0.15179.994>) started call event publisher
Apr 25 22:54:08 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.15430.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.15179.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.15430.994> to <0.15179.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.15179.994>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.publisher_usurp.0000265500002510000062ed00001f03%40SBC_IN) via <0.15430.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1144 (<0.15179.994>) channel started, let's connect
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.14956.994>) starting new gen_listener proc : ecallmgr_call_control
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:199 (<0.14956.994>) starting call control listener
Apr 25 22:54:08 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.9127.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.14956.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.9127.994> to <0.14956.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:1178 (<0.14956.994>) binding to call 0000265500002510000062ed00001f03@SBC_IN events on node freeswitch@FREESWITCH1-INT
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1144 (<0.14956.994>) channel started, let's connect
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_router_call:217 (<0.8657.994>) started event {ok,<0.15179.994>} and control {ok,<0.14956.994>} processes
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.18352.994>) Supervisor {<0.18352.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,193}) at pid <0.9792.992>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.18352.994>) Supervisor {<0.18352.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 193, <0.9792.992>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,193}) at pid <0.10899.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.18352.994>) Supervisor {<0.18352.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 193, 131072, rabbit_framing_amqp_0_9_1, <0.10899.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,193}) at pid <0.20163.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.18166.994>) Supervisor {<0.18166.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7210}) at pid <0.21282.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.18166.994>) Supervisor {<0.18166.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 7210, <0.21282.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7210}) at pid <0.18692.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.18166.994>) Supervisor {<0.18166.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 7210, 131072, rabbit_framing_amqp_0_9_1, <0.18692.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7210}) at pid <0.2439.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.10899.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:08 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.18692.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:302 (<0.14956.994>) declared queue kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29 via channel <0.9127.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:302 (<0.15179.994>) declared queue kazoo...@kazoo.DOMAIN-<0.15179.994>-2ce5bcfa via channel <0.15430.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:328 (<0.14956.994>) created consumer amq.ctag-58d01DIkbYDpmIt_N92D_Q via channel <0.9127.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:886 (<0.14956.994>) queue started: kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1035 (<0.14956.994>) creating new binding: 'call'
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:328 (<0.15179.994>) created consumer amq.ctag-PMWFskvusr7tV4pX8iDZiA via channel <0.15430.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:886 (<0.15179.994>) queue started: kazoo...@kazoo.DOMAIN-<0.15179.994>-2ce5bcfa
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1035 (<0.15179.994>) creating new binding: 'call'
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:321 (<0.14956.994>) bound kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29 to callevt exchange (routing key call.usurp_control.0000265500002510000062ed00001f03%40SBC_IN) via channel <0.9127.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1035 (<0.14956.994>) creating new binding: 'dialplan'
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:321 (<0.15179.994>) bound kazoo...@kazoo.DOMAIN-<0.15179.994>-2ce5bcfa to callevt exchange (routing key call.publisher_usurp.0000265500002510000062ed00001f03%40SBC_IN) via channel <0.15430.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:321 (<0.14956.994>) bound kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29 to callctl exchange (routing key kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29) via channel <0.9127.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1035 (<0.14956.994>) creating new binding: 'self'
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:321 (<0.14956.994>) bound kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29 to targeted exchange (routing key kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29) via channel <0.9127.994>
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:465 (<0.14956.994>) sending route_win to kazoo...@kazoo.DOMAIN-<0.964.0>-449f00df
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.14956.994>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.964.0>-449f00df) via <0.9127.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:473 (<0.14956.994>) sending control usurp for c9693fc7-54a2-42e1-b799-b79faf575780
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.14956.994>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.usurp_control.0000265500002510000062ed00001f03%40SBC_IN) via <0.9127.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:745 (<0.964.0>) response for msg id 0000265500002510000062ed00001f03@SBC_IN took 231684 micro to return
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_req:219 (<0.21625.994>) callflow has received a route win, taking control of the call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_win:37 (<0.21625.994>) setting initial information about the call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_win:242 (<0.21625.994>) no source endpoint for this call, setting language to default fi-fi
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_attributes:89 (<0.21625.994>) retaining original caller id <+3587777777> +3587777777
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_attributes:227 (<0.21625.994>) determined external caller id is <+3587777777> +3587777777
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_win:264 (<0.21625.994>) bootstrapping with caller id type external: "+3587777777" +3587777777
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.21625.994>) published to callctl(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29) via <0.1243.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_route_win:334 (<0.21625.994>) call has been setup, beginning to process the call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.8510.992>) starting new gen_listener proc : cf_exe
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.18953.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.8510.992>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.18953.994> to <0.8510.992>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:768 (<0.8510.992>) executing callflow da56fd0beb3d9360edcaa6f68f0a27c3
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:769 (<0.8510.992>) account id 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:770 (<0.8510.992>) request +3589123456@SBC1
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:771 (<0.8510.992>) to 09123456@SBC1
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:772 (<0.8510.992>) from +3587777777@SBC_IN
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:773 (<0.8510.992>) CID +3587777777 +3587777777
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:776 (<0.8510.992>) inception +3589123456@SBC1: using attributes for an external call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:778 (<0.8510.992>) authorizing id undefined
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1144 (<0.8510.992>) channel started, let's connect
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:884 (<0.14956.994>) recv and executing set now!
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:1033 (<0.14956.994>) executing call command 'set' 49f3138a5c017d071fc5c6cd5252bf71
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.16464.994>) Supervisor {<0.16464.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7209}) at pid <0.16801.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.16464.994>) Supervisor {<0.16464.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 7209, <0.16801.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7209}) at pid <0.17227.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.16464.994>) Supervisor {<0.16464.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 7209, 131072, rabbit_framing_amqp_0_9_1, <0.17227.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7209}) at pid <0.18106.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_router_call:220 (<0.8657.994>) xml fetch dialplan c9693fc7-54a2-42e1-b799-b79faf575780 finished with success
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:302 (<0.8510.992>) declared queue kazoo...@kazoo.DOMAIN-<0.8510.992>-be127737 via channel <0.18953.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:328 (<0.8510.992>) created consumer amq.ctag-lO6boD4d85KmTlL5L4lDgg via channel <0.18953.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:886 (<0.8510.992>) queue started: kazoo...@kazoo.DOMAIN-<0.8510.992>-be127737
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1035 (<0.8510.992>) creating new binding: 'call'
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.17227.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:321 (<0.8510.992>) bound kazoo...@kazoo.DOMAIN-<0.8510.992>-be127737 to callevt exchange (routing key call.*.0000265500002510000062ed00001f03%40SBC_IN) via channel <0.18953.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|gen_listener:1035 (<0.8510.992>) creating new binding: 'self'
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:321 (<0.8510.992>) bound kazoo...@kazoo.DOMAIN-<0.8510.992>-be127737 to targeted exchange (routing key kazoo...@kazoo.DOMAIN-<0.8510.992>-be127737) via channel <0.18953.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:489 (<0.8510.992>) ready to recv events, launching the callflow
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_exe:679 (<0.8510.992>) moving to action 'cf_user'
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_endpoint:837 (<0.16814.994>) creating call forwarding endpoint
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_endpoint:1208 (<0.16814.994>) call forwarding endpoint to 00456789
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_endpoint:820 (<0.16814.994>) failed to create endpoint: call_forward_substitute
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|cf_user:43 (<0.16814.994>) attempting 1 user devices with strategy simultaneous
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.16814.994>) published to callctl(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.14956.994>-aaa0af29) via <0.18953.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_call_command:2516 (<0.16814.994>) waiting for bridge for 80000 ms
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:943 (<0.14956.994>) inserting at the tail of the control queue call command bridge
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:1033 (<0.14956.994>) executing call command 'bridge' 027578960b2bb38d8a9d0da815e213ff
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_bridge:33 (<0.14956.994>) executing bridge on channel <<"0000265500002510000062ed00001f03@SBC_IN">>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_fs_bridge:50 (<0.14956.994>) creating bridge dialplan
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:640 (<0.14956.994>) building bridge endpoint: [<<"route">>,undefined,undefined,<<"+3589123456">>,<<"loopback/00456789">>,undefined,undefined]
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: set continue_on_fail=true
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: export sip_redirect_context=context_2
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: set hangup_after_bridge=true
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: export ecallmgr_Inception=${ecallmgr_Inception}
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: export ecallmgr_Call-Interaction-ID=${ecallmgr_Call-Interaction-ID}
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: bridge {call_timeout=60,originate_timeout=60,outbound_redirect_fatal='false',ignore_early_media='true',local_var_clobber='true'}[presence_id='10...@ACCOUNT.DOMAIN',ignore_early_media='true',leg_timeout='60',ecallmgr_Authorizing-ID='c7977a34493ff042b898cf74e32f2d94',ecallmgr_Owner-ID='b27257e420981374d1f81671cfa39a0b',ecallmgr_Account-ID='100000000001',ecallmgr_Call-Forward='true',ecallmgr_Authorizing-Type='device',loopback_bowout_on_execute='false',loopback_bowout='true',sdp_secure_savp_only='false',sip_invite_domain='SBC1']loopback/00456789/context_2
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: event Event-Name=CUSTOM,Event-Subclass=kazoo::masquerade,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=bridge
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:97 (<0.14956.994>) building xferext on node freeswitch@FREESWITCH1-INT: park
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.15179.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:710 (<0.15179.994>) publishing call event channel_execute_complete 'set(sip_redirect_context=context_2)' result: _none_
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.0000265500002510000062ed00001f03%40SBC_IN) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.15179.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.15179.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:710 (<0.15179.994>) publishing call event channel_execute_complete 'set(ecallmgr_Inception=+3589123456@SBC1)' result: _none_
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.0000265500002510000062ed00001f03%40SBC_IN) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.15179.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.15179.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:710 (<0.15179.994>) publishing call event channel_execute_complete 'set(ecallmgr_Call-Interaction-ID=63660369248-5320e328)' result: _none_
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.0000265500002510000062ed00001f03%40SBC_IN) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.15179.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.15179.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.15179.994>) publishing call event channel_progress_media
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_PROGRESS_MEDIA.0000265500002510000062ed00001f03%40SBC_IN) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.15179.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_call_events:706 (<0.21338.994>) publishing call event channel_create
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_CREATE.f62159ee-d636-4087-822d-7db6ead12107) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.21338.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_fs_authz:104 (<0.21338.994>) config ecallmgr.authz is disabled
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_fs_authz:236 (<0.21338.994>) channel authorization succeeded, allowing call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:706 (<0.23345.994>) publishing call event channel_create
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_CREATE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.23345.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_authz:104 (<0.23345.994>) config ecallmgr.authz is disabled
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_authz:236 (<0.23345.994>) channel authorization succeeded, allowing call
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_presence_amqp:198 (<0.20731.994>) received channel create, checking for presence subscribers
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_presence_amqp:319 (<0.20731.994>) no presence subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_dialog_amqp:197 (<0.21455.994>) received channel create, checking for dialog subscribers
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:816 (<0.1724.0>) storing {authz_response,<<"f62159ee-d636-4087-822d-7db6ead12107">>} for 3600s
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:818 (<0.1724.0>) inserted {authz_response,<<"f62159ee-d636-4087-822d-7db6ead12107">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:820 (<0.1724.0>) inserted origin pointers for {authz_response,<<"f62159ee-d636-4087-822d-7db6ead12107">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:822 (<0.1724.0>) exec store callbacks
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kapps_config:386 (<0.21455.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"early">>]: undefined
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_dialog_amqp:370 (<0.21455.994>) no dialog subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_presence_amqp:198 (<0.7097.994>) received channel create, checking for presence subscribers
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_presence_amqp:319 (<0.7097.994>) no presence subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|webhooks_channel_util:29 (<0.25536.994>) evt CHANNEL_CREATE for 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|webhooks_channel_util:31 (<0.25536.994>) no hooks to handle CHANNEL_CREATE for 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:816 (<0.1724.0>) storing {authz_response,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>} for 3600s
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:818 (<0.1724.0>) inserted {authz_response,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:820 (<0.1724.0>) inserted origin pointers for {authz_response,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:822 (<0.1724.0>) exec store callbacks
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_dialog_amqp:197 (<0.24610.994>) received channel create, checking for dialog subscribers
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kapps_config:386 (<0.24610.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"early">>]: undefined
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_dialog_amqp:370 (<0.24610.994>) no dialog subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_fs_authz:34 (<0.21338.994>) channel is authorized
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:29 (<0.24278.994>) evt CHANNEL_CREATE for 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:31 (<0.24278.994>) no hooks to handle CHANNEL_CREATE for 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:691 (<0.14956.994>) added leg f62159ee-d636-4087-822d-7db6ead12107 to call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.21434.994>) publishing call event leg_created
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.LEG_CREATED.0000265500002510000062ed00001f03%40SBC_IN) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.21434.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_authz:104 (<0.13222.994>) config ecallmgr.authz is disabled
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_authz:236 (<0.13222.994>) channel authorization succeeded, allowing call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_authz:34 (<0.23345.994>) channel is authorized
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.964.0>) published to callmgr(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key route.req.audio.100000000001) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:586 (<0.964.0>) published request with msg id c4243acd-feae-463c-aa70-123a2fbbd19d for <0.21291.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:816 (<0.1724.0>) storing {authz_response,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>} for 3600s
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:818 (<0.1724.0>) inserted {authz_response,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:820 (<0.1724.0>) inserted origin pointers for {authz_response,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:822 (<0.1724.0>) exec store callbacks
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_authz:34 (<0.13222.994>) channel is authorized
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_req:35 (<0.4361.994>) received request c4243acd-feae-463c-aa70-123a2fbbd19d asking if callflows can route this call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ts_route_req:26 (<0.24162.994>) received request c4243acd-feae-463c-aa70-123a2fbbd19d asking if trunkstore can route this call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ts_route_req:38 (<0.24162.994>) call with fetch-id c4243acd-feae-463c-aa70-123a2fbbd19d began on the network
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_flow:74 (<0.4361.994>) searching for callflow in account%2F10%2F64%20000002 to satisfy '00456789'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|milliwatt_route_req:37 (<0.24409.994>) milliwatt does not know what to do with this!
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ts_callflow:54 (<0.13402.994>) request is not for a trunkstore account
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.2268.0>) Supervisor ts_onnet_sup started ts_from_onnet:start_link({[{<<"Caller-ID-Number">>,<<"+3587777777">>},{<<"Caller-ID-Name">>,<<"3587777777">>},{<<"C...">>,...},...]}) at pid <0.13402.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_req:65 (<0.4361.994>) ignore preflow, not set
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_req:93 (<0.4361.994>) callflow ef3dc6fc6829f868dabb2094057ad412 in 100000000001 satisfies request
Apr 25 22:54:09 kazoo 2600hz[1307]: |00000000000|kz_token_bucket:203 (<0.30033.993>) consumed 5, 95 left
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_req:196 (<0.4361.994>) callflows knows how to route the call! sending park response
Apr 25 22:54:09 kazoo 2600hz[1307]: |c4243acd-feae-463c-aa70-123a2fbbd19d|kz_amqp_channel:159 (<0.959.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.964.0>-449f00df) via <0.933.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |c4243acd-feae-463c-aa70-123a2fbbd19d|kz_amqp_worker:586 (<0.959.0>) published request with msg id 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 for <0.4361.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |c4243acd-feae-463c-aa70-123a2fbbd19d|kz_amqp_worker:745 (<0.964.0>) response for msg id c4243acd-feae-463c-aa70-123a2fbbd19d took 13594 micro to return
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_router_util:94 (<0.21291.994>) received affirmative route response for request c4243acd-feae-463c-aa70-123a2fbbd19d
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_router_util:96 (<0.21291.994>) sending XML to freeswitch@FREESWITCH1-INT: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|kazoo...@kazoo.DOMAIN won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=kazoo...@kazoo.DOMAIN"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}" inline="true"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="kz_multiset" data="^^|ecallmgr_Call-Interaction-ID=63660369248-5320e328|ecallmgr_Fetch-ID=c4243acd-feae-463c-aa70-123a2fbbd19d|ecallmgr_Account-ID=100000000001|ecallmgr_Authorizing-ID=c7977a34493ff042b898cf74e32f2d94|ecallmgr_Authorizing-Type=device|ecallmgr_Bridge-ID=0000265500002510000062ed00001f03@SBC_IN|ecallmgr_Call-Forward=true|ecallmgr_Ecallmgr-Node=kazoo...@kazoo.DOMAIN|ecallmgr_Inception=+3589123456@SBC1|ecallmgr_Owner-ID=b27257e420981374d1f81671cfa39a0b|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_CallFlow-ID=ef3dc6fc6829f868dabb2094057ad412"/><action application="park"/></condition></extension></context></section></document>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:691 (<0.14956.994>) added leg 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 to call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.8744.994>) publishing call event leg_created
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.LEG_CREATED.0000265500002510000062ed00001f03%40SBC_IN) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.964.0>) published message 1493150049562398 for <0.8744.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_router_util:100 (<0.21291.994>) node freeswitch@FREESWITCH1-INT accepted dialplan route response for request c4243acd-feae-463c-aa70-123a2fbbd19d
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_event_sup:38 (<0.21291.994>) starting event handler for freeswitch@FREESWITCH1-INT
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.15925.994>) starting new gen_listener proc : ecallmgr_call_events
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:189 (<0.15925.994>) started call event publisher
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.7532.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.15925.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.7532.994> to <0.15925.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.15925.994>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.publisher_usurp.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.7532.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1144 (<0.15925.994>) channel started, let's connect
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.23361.994>) starting new gen_listener proc : ecallmgr_call_control
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:199 (<0.23361.994>) starting call control listener
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.16400.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.23361.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.16400.994> to <0.23361.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.23039.994>) Supervisor {<0.23039.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7208}) at pid <0.18797.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.23039.994>) Supervisor {<0.23039.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 7208, <0.18797.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7208}) at pid <0.24070.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.23039.994>) Supervisor {<0.23039.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 7208, 131072, rabbit_framing_amqp_0_9_1, <0.24070.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7208}) at pid <0.20384.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:1178 (<0.23361.994>) binding to call 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 events on node freeswitch@FREESWITCH1-INT
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1144 (<0.23361.994>) channel started, let's connect
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:302 (<0.15925.994>) declared queue kazoo...@kazoo.DOMAIN-<0.15925.994>-9ae2ffac via channel <0.7532.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.9337.994>) Supervisor {<0.9337.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7207}) at pid <0.17591.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.9337.994>) Supervisor {<0.9337.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 7207, <0.17591.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7207}) at pid <0.19231.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_router_call:217 (<0.21291.994>) started event {ok,<0.15925.994>} and control {ok,<0.23361.994>} processes
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.9337.994>) Supervisor {<0.9337.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 7207, 131072, rabbit_framing_amqp_0_9_1, <0.19231.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7207}) at pid <0.18795.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:302 (<0.23361.994>) declared queue kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7 via channel <0.16400.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.24070.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:328 (<0.23361.994>) created consumer amq.ctag-9brry_tuD6TeJmkQZAxAOg via channel <0.16400.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:886 (<0.23361.994>) queue started: kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.23361.994>) creating new binding: 'call'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:328 (<0.15925.994>) created consumer amq.ctag-bcbBXABG08mf7wTe5okShw via channel <0.7532.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:886 (<0.15925.994>) queue started: kazoo...@kazoo.DOMAIN-<0.15925.994>-9ae2ffac
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.15925.994>) creating new binding: 'call'
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.19231.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.15925.994>) bound kazoo...@kazoo.DOMAIN-<0.15925.994>-9ae2ffac to callevt exchange (routing key call.publisher_usurp.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.7532.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.23361.994>) bound kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7 to callevt exchange (routing key call.usurp_control.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.16400.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.23361.994>) creating new binding: 'dialplan'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.23361.994>) bound kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7 to callctl exchange (routing key kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7) via channel <0.16400.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.23361.994>) creating new binding: 'self'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.23361.994>) bound kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7 to targeted exchange (routing key kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7) via channel <0.16400.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:465 (<0.23361.994>) sending route_win to kazoo...@kazoo.DOMAIN-<0.959.0>-acd745e6
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.23361.994>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.959.0>-acd745e6) via <0.16400.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:473 (<0.23361.994>) sending control usurp for c4243acd-feae-463c-aa70-123a2fbbd19d
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.23361.994>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.usurp_control.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.16400.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:745 (<0.959.0>) response for msg id 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 took 25801 micro to return
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_req:219 (<0.4361.994>) callflow has received a route win, taking control of the call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|knm_converters:261 (<0.4361.994>) number '00456789' is classified as unknown
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_win:100 (<0.4361.994>) classified number 00456789 as unknown, testing for call restrictions
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_win:37 (<0.4361.994>) setting initial information about the call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:419 (<0.4361.994>) initiating endpoint is owned by b27257e420981374d1f81671cfa39a0b
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_win:239 (<0.4361.994>) setting language 'en-us' for this call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:136 (<0.4361.994>) endpoint configured with external caller id number +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:170 (<0.4361.994>) replacing empty caller id name with SIP caller id name 3587777777
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:223 (<0.4361.994>) determined external caller id is <3587777777> +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_win:264 (<0.4361.994>) bootstrapping with caller id type external: "3587777777" +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.4361.994>) published to callctl(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7) via <0.1243.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_win:334 (<0.4361.994>) call has been setup, beginning to process the call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.13821.994>) starting new gen_listener proc : cf_exe
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.24846.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.13821.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.24846.994> to <0.13821.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:768 (<0.13821.994>) executing callflow ef3dc6fc6829f868dabb2094057ad412
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:769 (<0.13821.994>) account id 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:770 (<0.13821.994>) request 0045...@nodomain.com
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:771 (<0.13821.994>) to 0045...@nodomain.com
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:772 (<0.13821.994>) from 10...@ACCOUNT.DOMAIN
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:773 (<0.13821.994>) CID 3587777777 +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:776 (<0.13821.994>) inception +3589123456@SBC1: using attributes for an external call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:778 (<0.13821.994>) authorizing id c7977a34493ff042b898cf74e32f2d94
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1144 (<0.13821.994>) channel started, let's connect
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_win:291 (<0.4361.994>) looking up endpoint for c7977a34493ff042b898cf74e32f2d94
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_route_win:294 (<0.4361.994>) trying to send metaflow for a-leg endpoint c7977a34493ff042b898cf74e32f2d94
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_endpoint:805 (<0.4361.994>) sending metaflow for endpoint: c7977a34493ff042b898cf74e32f2d94: undefined
Apr 25 22:54:09 kazoo 2600hz[1307]: |e4872667efe8cec2|kz_amqp_channel:159 (<0.959.0>) published to metaflow(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key metaflow.bind.100000000001.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.933.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |e4872667efe8cec2|kz_amqp_worker:663 (<0.959.0>) published message e4872667efe8cec2 for <0.4361.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.25098.994>) Supervisor {<0.25098.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7206}) at pid <0.27962.993>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.25098.994>) Supervisor {<0.25098.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 7206, <0.27962.993>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7206}) at pid <0.11107.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.25098.994>) Supervisor {<0.25098.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 7206, 131072, rabbit_framing_amqp_0_9_1, <0.11107.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7206}) at pid <0.24536.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:884 (<0.23361.994>) recv and executing set now!
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:1033 (<0.23361.994>) executing call command 'set' 868070f2b9f3e6087c922577e7433742
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:302 (<0.13821.994>) declared queue kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193 via channel <0.24846.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.11107.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_event_listener:145 (<0.19452.994>) add fsm binding for call 5e16a86d-e0ed-4e24-a51f-fca799fa49e2: [<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|gen_listener:1035 (<0.24690.985>) creating new binding: 'konami'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_router_call:220 (<0.21291.994>) xml fetch dialplan c4243acd-feae-463c-aa70-123a2fbbd19d finished with success
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:328 (<0.13821.994>) created consumer amq.ctag-OwxK-hosBjlkwSIQYLfncA via channel <0.24846.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:886 (<0.13821.994>) queue started: kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.13821.994>) creating new binding: 'call'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.13821.994>) bound kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193 to callevt exchange (routing key call.*.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.24846.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to kapps exchange (routing key konami.transferred.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.13821.994>) creating new binding: 'self'
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|konami_event_listener:362 (<0.24690.985>) registering for account events for 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|gen_listener:1057 (<0.24690.985>) creating existing binding 'call' with new props: [{restrict_to,[<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]},{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}]
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.13821.994>) bound kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193 to targeted exchange (routing key kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193) via channel <0.24846.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:489 (<0.13821.994>) ready to recv events, launching the callflow
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:679 (<0.13821.994>) moving to action 'cf_offnet'
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.DTMF.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_ANSWER.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_BRIDGE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_DESTROY.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_TRANSFEREE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.25025.994>) published to callctl(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7) via <0.24846.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:136 (<0.25025.994>) endpoint configured with emergency caller id number +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:170 (<0.25025.994>) replacing empty caller id name with SIP caller id name 3587777777
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:217 (<0.25025.994>) determined emergency caller id is <3587777777> +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:136 (<0.25025.994>) endpoint configured with external caller id number +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:170 (<0.25025.994>) replacing empty caller id name with SIP caller id name 3587777777
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_attributes:223 (<0.25025.994>) determined external caller id is <3587777777> +3589123456
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.25025.994>) published to resource(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key offnet.resource.req) via <0.24846.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_REPLACED.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_outbound:46 (<0.18343.994>) received outbound audio resource request for 00456789: {[{<<"Presence-ID">>,<<"10...@ACCOUNT.DOMAIN">>},{<<"Outbound-Caller-ID-Number">>,<<"+3589123456">>},{<<"Outbound-Caller-ID-Name">>,<<"3587777777">>},{<<"Inception">>,<<"+3589123456@SBC1">>},{<<"Ignore-Early-Media">>,<<"false">>},{<<"From-URI-Realm">>,<<"ACCOUNT.DOMAIN">>},{<<"Format-From-URI">>,false},{<<"Fax-T38-Enabled">>,false},{<<"Emergency-Caller-ID-Number">>,<<"+3589123456">>},{<<"Emergency-Caller-ID-Name">>,<<"3587777777">>},{<<"Custom-Channel-Vars">>,{[{<<"Caller-Screen-Bit">>,true},{<<"Authorizing-ID">>,<<"c7977a34493ff042b898cf74e32f2d94">>},{<<"Owner-ID">>,<<"b27257e420981374d1f81671cfa39a0b">>}]}},{<<"Control-Queue">>,<<"kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7">>},{<<"Call-ID">>,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>},{<<"Bypass-E164">>,false},{<<"B-Leg-Events">>,[<<"DTMF">>]},{<<"Account-Realm">>,<<"ACCOUNT.DOMAIN">>},{<<"Account-ID">>,<<"100000000001">>},{<<"To-DID">>,<<"00456789">>},{<<"Resource-Type">>,<<"audio">>},{<<"Application-Name">>,<<"bridge">>},{<<"Server-ID">>,<<"kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193">>},{<<"Node">>,<<"kazoo...@kazoo.DOMAIN">>},{<<"Msg-ID">>,<<"7b186d666da0">>},{<<"Event-Name">>,<<"offnet_req">>},{<<"Event-Category">>,<<"resource">>},{<<"App-Version">>,<<"4.0.0">>},{<<"App-Name">>,<<"callflow">>}]}
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|knm_phone_number:252 (<0.18343.994>) failed to open 00456789 in undefined: invalid_db_name
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|gen_listener:1057 (<0.24690.985>) creating existing binding 'metaflow' with new props: [{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>},{action,<<"*">>},{restrict_to,[action]},federate]
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to metaflow exchange (routing key metaflow.action.5e16a86d-e0ed-4e24-a51f-fca799fa49e2.*) via channel <0.19559.985>
Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|gen_listener:1079 (<0.24690.985>) no federated brokers to connect to, skipping federating binding 'metaflow'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:116 (<0.19452.994>) starting Konami FSM, listening on 'a'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:120 (<0.19452.994>) a endpoint: c7977a34493ff042b898cf74e32f2d94 b endpoint: undefined
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:324 (<0.19452.994>) loading default account metaflow numbers
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:336 (<0.19452.994>) loading patterns from api: {[{<<"2(\\d+)">>,{[{<<"module">>,<<"transfer">>},{<<"data">>,{[{<<"takeback_dtmf">>,<<"*1">>}]}}]}}]}
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:316 (<0.19452.994>) using custom binding digit '*'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|knm_port_request:104 (<0.18343.994>) failed to query for port number '00456789': not_found
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_resources:245 (<0.18343.994>) attempting to find global resources
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_resources:403 (<0.18343.994>) no flags provided, filtering resources that require flags
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_resources:539 (<0.18343.994>) resource XXX-carrier matches number '00456789' with regex match '00456789'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_resources:477 (<0.18343.994>) building resource XXX-carrier endpoints
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_resources:1153 (<0.18343.994>) created gateway route sip:00456789@SBC1
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_resources:1153 (<0.18343.994>) created gateway route sip:00456789@SBC1
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.19697.994>) starting new gen_listener proc : stepswitch_bridge
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.22323.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.19697.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.22323.994> to <0.19697.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1144 (<0.19697.994>) channel started, let's connect
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.2185.0>) Supervisor stepswitch_request_sup started stepswitch_bridge:start_link([{[{<<"Route">>,<<"sip:00456789@SBC1">>},{<<"Callee-ID-Name">>,<<"00456789">>},{<<"...">>,...},...]},...], {[{<<"Presence-ID">>,<<"10...@ACCOUNT.DOMAIN">>},{<<"Outbound-Caller-ID-Number">>,<<"+35894242180...">>},...]}) at pid <0.19697.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.21466.994>) Supervisor {<0.21466.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7205}) at pid <0.18311.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.21466.994>) Supervisor {<0.21466.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 7205, <0.18311.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7205}) at pid <0.18272.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.21466.994>) Supervisor {<0.21466.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 7205, 131072, rabbit_framing_amqp_0_9_1, <0.18272.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7205}) at pid <0.23777.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.18272.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:302 (<0.19697.994>) declared queue kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1 via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:328 (<0.19697.994>) created consumer amq.ctag-Ph5AjOwDLUCswmtjYCyI8g via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:886 (<0.19697.994>) queue started: kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.19697.994>) creating new binding: 'call'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.19697.994>) bound kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1 to callevt exchange (routing key call.CHANNEL_DESTROY.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.19697.994>) bound kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1 to callevt exchange (routing key call.CHANNEL_REPLACED.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.19697.994>) bound kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1 to callevt exchange (routing key call.CHANNEL_TRANSFEROR.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.19697.994>) bound kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1 to callevt exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.19697.994>) bound kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1 to callevt exchange (routing key call.CHANNEL_BRIDGE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1035 (<0.19697.994>) creating new binding: 'self'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.19697.994>) bound kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1 to targeted exchange (routing key kazoo...@kazoo.DOMAIN-<0.19697.994>-6644b7e1) via channel <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_bridge:367 (<0.19697.994>) set outbound caller id to +3589123456 '3587777777'
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.19697.994>) published to callctl(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7) via <0.22323.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_bridge:291 (<0.19697.994>) sent bridge command to kazoo...@kazoo.DOMAIN-<0.23361.994>-a9e6dfc7
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:884 (<0.23361.994>) recv and executing set now!
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:1033 (<0.23361.994>) executing call command 'set' 265356e5daf24cf177198af050c0a1e0
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:943 (<0.23361.994>) inserting at the tail of the control queue call command bridge
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:1033 (<0.23361.994>) executing call command 'bridge' 17277741accb8bbb7db1ceedd11e2903
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_bridge:33 (<0.23361.994>) executing bridge on channel <<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:116 (<0.23361.994>) sent msg to 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 to bind for b leg events [<<"DTMF">>]
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_fs_bridge:50 (<0.23361.994>) creating bridge dialplan
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:283 (<0.15925.994>) will start event listener for b-leg if encountered
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:640 (<0.23361.994>) building bridge endpoint: [<<"route">>,undefined,undefined,<<"00456789">>,<<"sip:00456789@SBC1">>,undefined,undefined]
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:640 (<0.23361.994>) building bridge endpoint: [<<"route">>,undefined,undefined,<<"00456789">>,<<"sip:00456789@SBC1">>,undefined,undefined]
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: kz_multiset ^^;ignore_display_updates=true;ecallmgr_Account-ID=100000000001;ecallmgr_Realm=ACCOUNT.DOMAIN;ecallmgr_Reseller-ID=89de3a164f98a27dffc576c9b04e506d;ecallmgr_Owner-ID=b27257e420981374d1f81671cfa39a0b;ecallmgr_Authorizing-ID=c7977a34493ff042b898cf74e32f2d94;ecallmgr_Caller-Screen-Bit=true
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: set continue_on_fail=true
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: export sip_redirect_context=context_2
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: set hangup_after_bridge=true
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: export ecallmgr_Inception=${ecallmgr_Inception}
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: export ecallmgr_Call-Interaction-ID=${ecallmgr_Call-Interaction-ID}
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: bridge {origination_caller_id_number='+3589123456',origination_caller_id_name='3587777777',ignore_early_media='false',ignore_display_updates='true',ecallmgr_Account-ID='100000000001',ecallmgr_Realm='ACCOUNT.DOMAIN',ecallmgr_Reseller-ID='89de3a164f98a27dffc576c9b04e506d',ecallmgr_Owner-ID='b27257e420981374d1f81671cfa39a0b',ecallmgr_Authorizing-ID='c7977a34493ff042b898cf74e32f2d94',ecallmgr_Caller-Screen-Bit='true',effective_caller_id_number='+3589123456',effective_caller_id_name='3587777777',local_var_clobber='true'}[leg_progress_timeout='15',ecallmgr_Global-Resource='true',ecallmgr_Resource-ID='XXX-carrier',ecallmgr_E164-Destination='00456789',ecallmgr_Original-Number='00456789',ecallmgr_Matched-Number='00456789',absolute_codec_string='^^:PCMA:PCMU',effective_callee_id_number='00456789',effective_callee_id_name='00456789']sofia/sipinterface_1/00456789@SBC1|[leg_progress_timeout='15',ecallmgr_Global-Resource='true',ecallmgr_Resource-ID='XXX-carrier',ecallmgr_E164-Destination='00456789',ecallmgr_Original-Number='00456789',ecallmgr_Matched-Number='00456789',absolute_codec_string='^^:PCMA:PCMU',effective_callee_id_number='00456789',effective_callee_id_name='00456789']sofia/sipinterface_1/00456789@SBC1
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: event Event-Name=CUSTOM,Event-Subclass=kazoo::masquerade,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=bridge
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_util:97 (<0.23361.994>) building xferext on node freeswitch@FREESWITCH1-INT: park
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:710 (<0.15925.994>) publishing call event channel_execute_complete 'set(sip_redirect_context=context_2)' result: _none_
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.933.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.959.0>) published message 1493150050042399 for <0.15925.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:710 (<0.15925.994>) publishing call event channel_execute_complete 'set(ecallmgr_Inception=+3589123456@SBC1)' result: _none_
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.933.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.959.0>) published message 1493150050042399 for <0.15925.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|ecallmgr_call_events:706 (<0.8719.994>) publishing call event channel_create
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:710 (<0.15925.994>) publishing call event channel_execute_complete 'set(ecallmgr_Call-Interaction-ID=63660369248-5320e328)' result: _none_
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:731 (<0.14956.994>) added cleg 2259313c-d46a-4f92-8e53-7303d22a6952 to call
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.4439.994>) publishing call event leg_created
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.964.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.953.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.964.0>) published message 1493150050042399 for <0.15925.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_CREATE.2259313c-d46a-4f92-8e53-7303d22a6952) via <0.933.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.LEG_CREATED.0000265500002510000062ed00001f03%40SBC_IN) via <0.925.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_worker:663 (<0.959.0>) published message 1493150050042399 for <0.8719.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.907.0>) published message 1493150050042399 for <0.4439.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|ecallmgr_fs_authz:104 (<0.8719.994>) config ecallmgr.authz is disabled
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|ecallmgr_fs_authz:236 (<0.8719.994>) channel authorization succeeded, allowing call
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:816 (<0.1724.0>) storing {authz_response,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>} for 3600s
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:818 (<0.1724.0>) inserted {authz_response,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:820 (<0.1724.0>) inserted origin pointers for {authz_response,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>}
Apr 25 22:54:09 kazoo 2600hz[1307]: |2ca84d6be57cd09d|kz_cache:822 (<0.1724.0>) exec store callbacks
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_presence_amqp:198 (<0.23604.994>) received channel create, checking for presence subscribers
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_presence_amqp:319 (<0.23604.994>) no presence subscriptions for +3587...@ACCOUNT.DOMAIN
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_dialog_amqp:197 (<0.11773.994>) received channel create, checking for dialog subscribers
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kapps_config:386 (<0.11773.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"early">>]: undefined
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_dialog_amqp:370 (<0.11773.994>) no dialog subscriptions for +3587...@ACCOUNT.DOMAIN
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|webhooks_channel_util:29 (<0.18090.994>) evt CHANNEL_CREATE for 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|webhooks_channel_util:31 (<0.18090.994>) no hooks to handle CHANNEL_CREATE for 100000000001
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:691 (<0.23361.994>) added leg 2259313c-d46a-4f92-8e53-7303d22a6952 to call
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:706 (<0.23750.994>) publishing call event leg_created
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.LEG_CREATED.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.925.0>
Apr 25 22:54:09 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.907.0>) published message 1493150050042399 for <0.23750.994>
Apr 25 22:54:09 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|ecallmgr_fs_authz:34 (<0.8719.994>) channel is authorized
Apr 25 22:54:13 kazoo 2600hz[1307]: |67eaa69b930f37ba|kz_amqp_channel:159 (<0.907.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.925.0>
Apr 25 22:54:13 kazoo 2600hz[1307]: |67eaa69b930f37ba|kz_amqp_worker:663 (<0.907.0>) published message 67eaa69b930f37ba for <0.1226.0>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:706 (<0.15925.994>) publishing call event channel_progress_media
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_PROGRESS_MEDIA.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.925.0>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.907.0>) published message 1493150053622451 for <0.15925.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:704 (<0.15925.994>) publishing channel_bridge to other leg 2259313c-d46a-4f92-8e53-7303d22a6952
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_BRIDGE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.925.0>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.907.0>) published message 1493150053622451 for <0.15925.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:301 (<0.15925.994>) tracking other leg events for 2259313c-d46a-4f92-8e53-7303d22a6952: [<<"DTMF">>]
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_event_sup:38 (<0.15925.994>) starting event handler for freeswitch@FREESWITCH1-INT
Apr 25 22:54:13 kazoo 2600hz[1307]: |0000000000|gen_listener:381 (<0.19815.994>) starting new gen_listener proc : ecallmgr_call_events
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|ecallmgr_call_events:189 (<0.19815.994>) started call event publisher
Apr 25 22:54:13 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:475 (<0.138.0>) assigned existing channel <0.24955.994> on amqp://guest:gu...@127.0.0.1:5672 to new consumer <0.19815.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:886 (<0.138.0>) registered handlers for channel <0.24955.994> to <0.19815.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:304 (<0.15925.994>) started event process: {ok,<0.19815.994>}
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_channel:159 (<0.19815.994>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.publisher_usurp.2259313c-d46a-4f92-8e53-7303d22a6952) via <0.24955.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|gen_listener:1144 (<0.19815.994>) channel started, let's connect
Apr 25 22:54:13 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.19872.994>) Supervisor {<0.19872.994>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7204}) at pid <0.20187.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.19872.994>) Supervisor {<0.19872.994>,amqp_channel_sup} started amqp_channel:start_link(network, <0.144.0>, 7204, <0.20187.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7204}) at pid <0.5788.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.19872.994>) Supervisor {<0.19872.994>,amqp_channel_sup} started rabbit_writer:start_link(#Port<0.3679>, 7204, 131072, rabbit_framing_amqp_0_9_1, <0.5788.994>, {<<"client 127.0.0.1:44881 -> 127.0.0.1:5672">>,7204}) at pid <0.20792.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_bridge:162 (<0.19697.994>) channel bridged to 2259313c-d46a-4f92-8e53-7303d22a6952, canceling timeout
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:605 (<0.19452.994>) joy, 'a' is bridged to 2259313c-d46a-4f92-8e53-7303d22a6952
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_event_listener:145 (<0.19452.994>) add fsm binding for call 2259313c-d46a-4f92-8e53-7303d22a6952: [<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:29 (<0.14885.994>) evt CHANNEL_BRIDGE for 100000000001
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:31 (<0.14885.994>) no hooks to handle CHANNEL_BRIDGE for 100000000001
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1057 (<0.24690.985>) creating existing binding 'call' with new props: [{restrict_to,[<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]},{callid,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>}]
Apr 25 22:54:13 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:600 (<0.138.0>) added new channel <0.5788.994> on amqp://guest:gu...@127.0.0.1:5672 to available pool
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_channel:302 (<0.19815.994>) declared queue kazoo...@kazoo.DOMAIN-<0.19815.994>-02d610f7 via channel <0.24955.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_channel:328 (<0.19815.994>) created consumer amq.ctag-8vCcU97Ao2_s3PTx7nbCJg via channel <0.24955.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|gen_listener:886 (<0.19815.994>) queue started: kazoo...@kazoo.DOMAIN-<0.19815.994>-02d610f7
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|gen_listener:1035 (<0.19815.994>) creating new binding: 'call'
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.DTMF.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:13 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_channel:321 (<0.19815.994>) bound kazoo...@kazoo.DOMAIN-<0.19815.994>-02d610f7 to callevt exchange (routing key call.publisher_usurp.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.24955.994>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_ANSWER.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_BRIDGE.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_DESTROY.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_TRANSFEREE.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to callevt exchange (routing key call.CHANNEL_REPLACED.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1057 (<0.24690.985>) creating existing binding 'metaflow' with new props: [{callid,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>},{action,<<"*">>},{restrict_to,[action]},federate]
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to metaflow exchange (routing key metaflow.action.2259313c-d46a-4f92-8e53-7303d22a6952.*) via channel <0.19559.985>
Apr 25 22:54:13 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:1079 (<0.24690.985>) no federated brokers to connect to, skipping federating binding 'metaflow'
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|ecallmgr_call_events:706 (<0.28345.993>) publishing call event channel_answer
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_ANSWER.2259313c-d46a-4f92-8e53-7303d22a6952) via <0.925.0>
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kz_amqp_worker:663 (<0.907.0>) published message 1493150056142454 for <0.28345.993>
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:560 (<0.19452.994>) 'b' leg 2259313c-d46a-4f92-8e53-7303d22a6952 answered
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:560 (<0.19452.994>) 'b' leg 2259313c-d46a-4f92-8e53-7303d22a6952 answered
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_presence_amqp:205 (<0.22064.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_dialog_amqp:202 (<0.20871.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_presence_amqp:319 (<0.22064.994>) no presence subscriptions for +3587...@ACCOUNT.DOMAIN
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|kapps_config:386 (<0.20871.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"confirmed">>]: undefined
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|omnip_dialog_amqp:370 (<0.20871.994>) no dialog subscriptions for +3587...@ACCOUNT.DOMAIN
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|webhooks_channel_util:29 (<0.17344.994>) evt CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |2259313c-d46a-4f92-8e53-7303d22a6952|webhooks_channel_util:31 (<0.17344.994>) no hooks to handle CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_call_events:706 (<0.24711.994>) publishing call event channel_answer
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_ANSWER.f62159ee-d636-4087-822d-7db6ead12107) via <0.925.0>
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kz_amqp_worker:663 (<0.907.0>) published message 1493150056162414 for <0.24711.994>
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:706 (<0.25462.994>) publishing call event channel_answer
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_ANSWER.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.925.0>
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.907.0>) published message 1493150056162414 for <0.25462.994>
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_presence_amqp:205 (<0.17901.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_presence_amqp:319 (<0.17901.994>) no presence subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_dialog_amqp:202 (<0.20942.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kapps_config:386 (<0.20942.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"confirmed">>]: undefined
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_dialog_amqp:370 (<0.20942.994>) no dialog subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:576 (<0.19452.994>) channel f62159ee-d636-4087-822d-7db6ead12107 answered while on 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 and 2259313c-d46a-4f92-8e53-7303d22a6952
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|webhooks_channel_util:29 (<0.24126.994>) evt CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|webhooks_channel_util:31 (<0.24126.994>) no hooks to handle CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:29 (<0.14151.994>) evt CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:31 (<0.14151.994>) no hooks to handle CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:557 (<0.19452.994>) 'a' leg 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 answered
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_presence_amqp:205 (<0.16160.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_presence_amqp:319 (<0.16160.994>) no presence subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_dialog_amqp:202 (<0.17226.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kapps_config:386 (<0.17226.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"confirmed">>]: undefined
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_dialog_amqp:370 (<0.17226.994>) no dialog subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:557 (<0.19452.994>) 'a' leg 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 answered
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.9220.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.9220.994>) publishing call event channel_answer
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_ANSWER.0000265500002510000062ed00001f03%40SBC_IN) via <0.925.0>
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.907.0>) published message 1493150056182423 for <0.9220.994>
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.15179.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:704 (<0.15179.994>) publishing channel_bridge to other leg f62159ee-d636-4087-822d-7db6ead12107
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_BRIDGE.0000265500002510000062ed00001f03%40SBC_IN) via <0.925.0>
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.907.0>) published message 1493150056182423 for <0.15179.994>
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:301 (<0.15179.994>) tracking other leg events for f62159ee-d636-4087-822d-7db6ead12107: []
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:304 (<0.15179.994>) started event process: false
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_presence_amqp:205 (<0.15809.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_presence_amqp:319 (<0.15809.994>) no presence subscriptions for +3587777777@SBC_IN
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_dialog_amqp:202 (<0.20051.994>) received channel answer, checking for subscribers
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_config:386 (<0.20051.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"confirmed">>]: undefined
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|omnip_dialog_amqp:370 (<0.20051.994>) no dialog subscriptions for +3587777777@SBC_IN
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:29 (<0.11847.994>) evt CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:31 (<0.11847.994>) no hooks to handle CHANNEL_ANSWER for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:29 (<0.18967.994>) evt CHANNEL_BRIDGE for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:31 (<0.18967.994>) no hooks to handle CHANNEL_BRIDGE for 100000000001
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_call_command:2537 (<0.16814.994>) channel bridged to f62159ee-d636-4087-822d-7db6ead12107
Apr 25 22:54:15 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_call_command:2516 (<0.16814.994>) waiting for bridge for infinity ms
Apr 25 22:54:15 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:576 (<0.19452.994>) channel 0000265500002510000062ed00001f03@SBC_IN answered while on 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 and 2259313c-d46a-4f92-8e53-7303d22a6952
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.15179.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.15179.994>) publishing call event channel_unbridge
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:582 (<0.14956.994>) bridge execute complete, advancing control queue
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:614 (<0.14956.994>) no call commands remain queued, hibernating
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_UNBRIDGE.0000265500002510000062ed00001f03%40SBC_IN) via <0.925.0>
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.907.0>) published message 1493150058242415 for <0.15179.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:913 (<0.15179.994>) suppressing bridge execute complete in favour the kazoo masquerade of this event
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:706 (<0.15925.994>) publishing call event channel_unbridge
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_control:780 (<0.14956.994>) removed leg f62159ee-d636-4087-822d-7db6ead12107 from call
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:706 (<0.11814.994>) publishing call event leg_destroyed
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.907.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_UNBRIDGE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.925.0>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.907.0>) published message 1493150058242415 for <0.15925.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:913 (<0.15925.994>) suppressing bridge execute complete in favour the kazoo masquerade of this event
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:582 (<0.23361.994>) bridge execute complete, advancing control queue
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:816 (<0.1733.0>) storing {channel,<<"f62159ee-d636-4087-822d-7db6ead12107">>} for 3600s
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:818 (<0.1733.0>) inserted {channel,<<"f62159ee-d636-4087-822d-7db6ead12107">>}
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:820 (<0.1733.0>) inserted origin pointers for {channel,<<"f62159ee-d636-4087-822d-7db6ead12107">>}
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:822 (<0.1733.0>) exec store callbacks
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.LEG_DESTROYED.0000265500002510000062ed00001f03%40SBC_IN) via <0.933.0>
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.959.0>) published message 1493150058242415 for <0.11814.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:614 (<0.23361.994>) no call commands remain queued, hibernating
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:630 (<0.23361.994>) checking interaction cache for 5e16a86d-e0ed-4e24-a51f-fca799fa49e2
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:637 (<0.23361.994>) interaction cache for 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 not found
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:488 (<0.23361.994>) our channel has been destroyed, executing any post-hangup commands
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:1156 (<0.23361.994>) started post hangup keep alive timer for 120000ms
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:630 (<0.23361.994>) checking interaction cache for 5e16a86d-e0ed-4e24-a51f-fca799fa49e2
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:637 (<0.23361.994>) interaction cache for 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 not found
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:488 (<0.23361.994>) our channel has been destroyed, executing any post-hangup commands
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_control:1167 (<0.23361.994>) reset post hangup keep alive timer
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:816 (<0.1733.0>) storing {channel,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>} for 3600s
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:267 (<0.15925.994>) call event listener on node freeswitch@FREESWITCH1-INT received graceful shutdown request
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:818 (<0.1733.0>) inserted {channel,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:820 (<0.1733.0>) inserted origin pointers for {channel,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}
Apr 25 22:54:17 kazoo 2600hz[1307]: |ecallmgr_interaction_cache|kz_cache:822 (<0.1733.0>) exec store callbacks
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:630 (<0.21788.994>) checking interaction cache for 5e16a86d-e0ed-4e24-a51f-fca799fa49e2
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:637 (<0.21788.994>) interaction cache for 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 not found
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:706 (<0.21788.994>) publishing call event channel_destroy
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_DESTROY.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via <0.933.0>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_worker:663 (<0.959.0>) published message 1493150058242415 for <0.21788.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |00004f5800002a8e0000514d00000528@SBC_IN|ecallmgr_fs_channels:444 (<0.1761.0>) removed 1 channel(s) with id f62159ee-d636-4087-822d-7db6ead12107 on freeswitch@FREESWITCH1-INT
Apr 25 22:54:17 kazoo 2600hz[1307]: |00004f5800002a8e0000514d00000528@SBC_IN|ecallmgr_fs_channels:444 (<0.1761.0>) removed 1 channel(s) with id 5e16a86d-e0ed-4e24-a51f-fca799fa49e2 on freeswitch@FREESWITCH1-INT
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_call_events:630 (<0.17764.994>) checking interaction cache for f62159ee-d636-4087-822d-7db6ead12107
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_call_events:637 (<0.17764.994>) interaction cache for f62159ee-d636-4087-822d-7db6ead12107 not found
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|ecallmgr_call_events:706 (<0.17764.994>) publishing call event channel_destroy
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_DESTROY.f62159ee-d636-4087-822d-7db6ead12107) via <0.933.0>
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kz_amqp_worker:663 (<0.959.0>) published message 1493150058242415 for <0.17764.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_resources:51 (<0.25025.994>) completed successful offnet request
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_bridge:222 (<0.19697.994>) channel was destroyed while waiting for bridge
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:29 (<0.16559.994>) evt CHANNEL_DESTROY for 100000000001
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|webhooks_channel_util:29 (<0.16589.994>) evt CHANNEL_DESTROY for 100000000001
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|webhooks_channel_util:31 (<0.16589.994>) no hooks to handle CHANNEL_DESTROY for 100000000001
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_presence_amqp:212 (<0.14345.994>) received channel destroy, checking for presence subscribers
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_presence_amqp:319 (<0.14345.994>) no presence subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_dialog_amqp:207 (<0.24110.994>) received channel destroy, checking for dialog subscribers
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:643 (<0.19452.994>) 'a' leg has ended, so should we
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kapps_config:386 (<0.24110.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"terminated">>]: undefined
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|omnip_dialog_amqp:370 (<0.24110.994>) no dialog subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|konami_code_fsm:295 (<0.19452.994>) fsm terminating while in unarmed: normal
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:567 (<0.24690.985>) removing call: [{restrict_to,[<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]},{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}]
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_bridge:534 (<0.19697.994>) outbound request successfully completed
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|webhooks_channel_util:31 (<0.16559.994>) no hooks to handle CHANNEL_DESTROY for 100000000001
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:901 (<0.24690.985>) trying to remove bindings with kapi_call:unbind_q(kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac, [{restrict_to,[<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]},{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>}])
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|cf_exe:606 (<0.13821.994>) callflow execution has been transferred
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:95 (<0.13821.994>) release consumer <0.13821.994> channel assignment
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.DTMF.5e16a86d-e0ed-4e24-a51f-fca799fa49e2)
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:893 (<0.138.0>) unregistered handlers for channel <0.24846.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:721 (<0.13821.994>) cf_exe terminated cleanly, going down
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_channel:113 (<0.138.0>) ensuring queue kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193 is removed
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_channel:108 (<0.138.0>) ensuring amq.ctag-OwxK-hosBjlkwSIQYLfncA is removed
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:159 (<0.19697.994>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193) via <0.22323.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|stepswitch_bridge:260 (<0.19697.994>) listener terminating: normal
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:95 (<0.19697.994>) release consumer <0.19697.994> channel assignment
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_presence_amqp:212 (<0.25676.994>) received channel destroy, checking for presence subscribers
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_presence_amqp:319 (<0.25676.994>) no presence subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_dialog_amqp:207 (<0.18517.994>) received channel destroy, checking for dialog subscribers
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|kapps_config:386 (<0.18517.994>) setting default for omnipresence [<<"broadcast_presence">>,<<"terminated">>]: undefined
Apr 25 22:54:17 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|omnip_dialog_amqp:370 (<0.18517.994>) no dialog subscriptions for 10...@ACCOUNT.DOMAIN
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_history|kz_amqp_history:301 (<0.139.0>) removing AMQP history for consumer <0.13821.994> in 2.5s: {shutdown,transfer}
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000000000|Undefined:Undefined (<0.24846.994>) Channel (<0.24846.994>): dropping method {{'basic.deliver',<<"amq.ctag-OwxK-hosBjlkwSIQYLfncA">>,10,false,<<"targeted">>,<<"kazoo...@kazoo.DOMAIN-<0.13821.994>-59d0a193">>},{content,60,none,<<128,0,16,97,112,112,108,105,99,97,116,105,111,110,47,106,115,111,110>>,rabbit_framing_amqp_0_9_1,[<<"{\"Resource-Response\":{\"To\":\"0045...@ACCOUNT.DOMAIN\",\"Timestamp\":63660369258,\"Switch-URL\":\"sip:mod_sofia@FREESWITCH1:11000\",\"Switch-URI\":\"sip:FREESWITCH1:11000\",\"Switch-Nodename\":\"freeswitch@FREESWITCH1-INT\",\"Ringing-Seconds\":\"0\",\"Request\":\"0045...@ACCOUNT.DOMAIN\",\"Presence-ID\":\"10...@ACCOUNT.DOMAIN\",\"Other-Leg-Direction\":\"outbound\",\"Other-Leg-Destination-Number\":\"00456789\",\"Other-Leg-Caller-ID-Number\":\"+3589123456\",\"Other-Leg-Caller-ID-Name\":\"3587777777\",\"Other-Leg-Call-ID\":\"2259313c-d46a-4f92-8e53-7303d22a6952\",\"Media-Server\":\"FS1HOSTNAME.DOMAIN\",\"Hangup-Cause\":\"NORMAL_CLEARING\",\"From\":\"10...@ACCOUNT.DOMAIN\",\"Duration-Seconds\":\"9\",\"Disposition\":\"SUCCESS\",\"Custom-SIP-Headers\":{},\"Custom-Channel-Vars\":{\"Account-ID\":\"100000000001\",\"Application-Name\":\"callflow\",\"Application-Node\":\"kazoo...@kazoo.DOMAIN\",\"Authorizing-ID\":\"c7977a34493ff042b898cf74e32f2d94\",\"Authorizing-Type\":\"device\",\"Bridge-ID\":\"0000265500002510000062ed00001f03@SBC_IN\",\"Call-Forward\":\"true\",\"Call-Interaction-ID\":\"63660369248-5320e328\",\"CallFlow-ID\":\"ef3dc6fc6829f868dabb2094057ad412\",\"Caller-Privacy-Hide-Name\":\"false\",\"Caller-Privacy-Hide-Number\":\"false\",\"Caller-Screen-Bit\":\"true\",\"Channel-Authorized\":\"true\",\"Ecallmgr-Node\":\"kazoo...@kazoo.DOMAIN\",\"Fetch-ID\":\"c4243acd-feae-463c-aa70-123a2fbbd19d\",\"Global-Resource\":\"false\",\"Inception\":\"+3589123456@SBC1\",\"Owner-ID\":\"b27257e420981374d1f81671cfa39a0b\",\"Realm\":\"ACCOUNT.DOMAIN\",\"Reseller-ID\":\"89de3a164f98a27dffc576c9b04e506d\"},\"Channel-State\":\"REPORTING\",\"Channel-Name\":\"loopback/00456789-b\",\"Channel-Loopback-Other-Leg-ID\":\"f62159ee-d636-4087-822d-7db6ead12107\",\"Channel-Loopback-Leg\":\"B\",\"Channel-Loopback-Bowout-Execute\":false,\"Channel-Loopback-Bowout\":true,\"Channel-Is-Loopback\":true,\"Channel-Created-Time\":1493150049562398,\"Channel-Call-State\":\"HANGUP\",\"Caller-ID-Number\":\"+3589123456\",\"Caller-ID-Name\":\"3587777777\",\"Callee-ID-Number\":\"context_2\",\"Callee-ID-Name\":\"Outbound Call\",\"Call-Direction\":\"inbound\",\"Billing-Seconds\":\"3\",\"Call-ID\":\"5e16a86d-e0ed-4e24-a51f-fca799fa49e2\",\"Node\":\"kazoo...@kazoo.DOMAIN\",\"Msg-ID\":\"1493150058242415\",\"Event-Name\":\"CHANNEL_DESTROY\",\"Event-Category\":\"call_event\",\"App-Version\":\"4.0.0\",\"App-Name\":\"ecallmgr\"},\"Call-ID\":\"5e16a86d-e0ed-4e24-a51f-fca799fa49e2\",\"Response-Code\":\"sip:200\",\"Response-Message\":\"SUCCESS\",\"Node\":\"kazoo...@kazoo.DOMAIN\",\"Msg-ID\":\"7b186d666da0\",\"Event-Name\":\"offnet_resp\",\"Event-Category\":\"resource\",\"App-Version\":\"4.0.0\",\"App-Name\":\"stepswitch\"}">>]}} from server because channel is closing
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.DTMF.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_channel:105 (<0.138.0>) closed amqp channel <0.24846.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:300 (<0.138.0>) removed assignment for consumer <0.13821.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:893 (<0.138.0>) unregistered handlers for channel <0.22323.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:721 (<0.19697.994>) stepswitch_bridge terminated cleanly, going down
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_history|kz_amqp_history:301 (<0.139.0>) removing AMQP history for consumer <0.19697.994> in 2.5s: normal
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_ANSWER.5e16a86d-e0ed-4e24-a51f-fca799fa49e2)
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_channel:105 (<0.138.0>) closed amqp channel <0.22323.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:300 (<0.138.0>) removed assignment for consumer <0.19697.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_ANSWER.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_BRIDGE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_BRIDGE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_DESTROY.5e16a86d-e0ed-4e24-a51f-fca799fa49e2)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_DESTROY.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_TRANSFEREE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2)
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.14956.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_util:1238 (<0.15179.994>) adding diversion sip:09123456@DOMAIN;user=phone to SIP headers
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:704 (<0.15179.994>) publishing channel_bridge to other leg 2259313c-d46a-4f92-8e53-7303d22a6952
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.CHANNEL_BRIDGE.0000265500002510000062ed00001f03%40SBC_IN) via <0.933.0>
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.959.0>) published message 1493150058282397 for <0.15179.994>
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:301 (<0.15179.994>) tracking other leg events for 2259313c-d46a-4f92-8e53-7303d22a6952: []
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|ecallmgr_call_events:304 (<0.15179.994>) started event process: false
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_TRANSFEREE.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_call_command:2537 (<0.16814.994>) channel bridged to 2259313c-d46a-4f92-8e53-7303d22a6952
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kapps_call_command:2516 (<0.16814.994>) waiting for bridge for infinity ms
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_REPLACED.5e16a86d-e0ed-4e24-a51f-fca799fa49e2)
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:29 (<0.22177.994>) evt CHANNEL_BRIDGE for 100000000001
Apr 25 22:54:17 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|webhooks_channel_util:31 (<0.22177.994>) no hooks to handle CHANNEL_BRIDGE for 100000000001
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_REPLACED.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:567 (<0.24690.985>) removing metaflow: [{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>},{action,<<"*">>},{restrict_to,[action]},federate]
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:901 (<0.24690.985>) trying to remove bindings with kapi_metaflow:unbind_q(kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac, [{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>},{action,<<"*">>},{restrict_to,[action]},federate])
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from metaflow(metaflow.action.5e16a86d-e0ed-4e24-a51f-fca799fa49e2.*)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from metaflow exchange (routing key metaflow.action.5e16a86d-e0ed-4e24-a51f-fca799fa49e2.*) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:567 (<0.24690.985>) removing call: [{restrict_to,[<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]},{callid,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>}]
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:901 (<0.24690.985>) trying to remove bindings with kapi_call:unbind_q(kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac, [{restrict_to,[<<"DTMF">>,<<"CHANNEL_ANSWER">>,<<"CHANNEL_BRIDGE">>,<<"CHANNEL_DESTROY">>,<<"CHANNEL_TRANSFEREE">>,<<"CHANNEL_REPLACED">>]},{callid,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>}])
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.DTMF.2259313c-d46a-4f92-8e53-7303d22a6952)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.DTMF.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_ANSWER.2259313c-d46a-4f92-8e53-7303d22a6952)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_ANSWER.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_BRIDGE.2259313c-d46a-4f92-8e53-7303d22a6952)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_BRIDGE.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_DESTROY.2259313c-d46a-4f92-8e53-7303d22a6952)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_DESTROY.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_TRANSFEREE.2259313c-d46a-4f92-8e53-7303d22a6952)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_TRANSFEREE.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt(call.CHANNEL_REPLACED.2259313c-d46a-4f92-8e53-7303d22a6952)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from callevt exchange (routing key call.CHANNEL_REPLACED.2259313c-d46a-4f92-8e53-7303d22a6952) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:567 (<0.24690.985>) removing metaflow: [{callid,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>},{action,<<"*">>},{restrict_to,[action]},federate]
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:901 (<0.24690.985>) trying to remove bindings with kapi_metaflow:unbind_q(kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac, [{callid,<<"2259313c-d46a-4f92-8e53-7303d22a6952">>},{action,<<"*">>},{restrict_to,[action]},federate])
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from metaflow(metaflow.action.2259313c-d46a-4f92-8e53-7303d22a6952.*)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from metaflow exchange (routing key metaflow.action.2259313c-d46a-4f92-8e53-7303d22a6952.*) via channel <0.19559.985>
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:567 (<0.24690.985>) removing konami: [{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>},{restrict_to,[transferred]}]
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:901 (<0.24690.985>) trying to remove bindings with kapi_konami:unbind_q(kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac, [{callid,<<"5e16a86d-e0ed-4e24-a51f-fca799fa49e2">>},{restrict_to,[transferred]}])
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:253 (<0.24690.985>) unbinding kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from kapps(konami.transferred.5e16a86d-e0ed-4e24-a51f-fca799fa49e2)
Apr 25 22:54:17 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:311 (<0.24690.985>) unbound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac from kapps exchange (routing key konami.transferred.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>
Apr 25 22:54:18 kazoo 2600hz[1307]: |0000000000|kz_amqp_channel:159 (<0.1718.0>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key statistics) via <0.1743.0>
Apr 25 22:54:19 kazoo 2600hz[1307]: |7773f7f82d56a583|kz_amqp_channel:159 (<0.959.0>) published to nodes(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key ) via <0.933.0>
Apr 25 22:54:19 kazoo 2600hz[1307]: |7773f7f82d56a583|kz_amqp_worker:663 (<0.959.0>) published message 7773f7f82d56a583 for <0.1226.0>
Apr 25 22:54:19 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|knm_converters:261 (<0.21540.994>) number '00456789' is classified as unknown
Apr 25 22:54:20 kazoo 2600hz[1307]: |f62159ee-d636-4087-822d-7db6ead12107|knm_converters:261 (<0.18878.994>) number '00456789' is classified as unknown
Apr 25 22:54:21 kazoo 2600hz[1307]: |f529e88e-135d-4b31-9340-e9dcbcd8cf02|kz_nodes:570 (<0.1226.0>) VM sup_...@kazoo.DOMAIN is now connected:
Apr 25 22:54:21 kazoo 2600hz[1307]: |f529e88e-135d-4b31-9340-e9dcbcd8cf02|kz_nodes:571 (<0.1226.0>)  node_type: hidden
Apr 25 22:54:21 kazoo 2600hz[1307]: |f529e88e-135d-4b31-9340-e9dcbcd8cf02|kz_nodes:563 (<0.1226.0>) VM sup_...@kazoo.DOMAIN is no longer connected:
Apr 25 22:54:21 kazoo 2600hz[1307]: |f529e88e-135d-4b31-9340-e9dcbcd8cf02|kz_nodes:564 (<0.1226.0>)  nodedown_reason: connection_closed
Apr 25 22:54:21 kazoo 2600hz[1307]: |f529e88e-135d-4b31-9340-e9dcbcd8cf02|kz_nodes:564 (<0.1226.0>)  node_type: hidden
Apr 25 22:54:21 kazoo 2600hz[1307]: |0000000000|crossbar_init:40 (<0.21885.994>) routing to version 2
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_util:171 (<0.21885.994>) query string: <<"{\"auth_token\":\"eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6ImM0NzgyNjRhNmUzZmRlZDVjYzg3MTQ3ZTZhOWY4YWNlIn0.eyJpc3MiOiJrYXpvbyIsImlkZW50aXR5X3NpZyI6IlhhbFZKWUdISll4eTdYX1o4RVAwX1RaNnRCaWdyUXVvSVpEMU83a3FPVVEiLCJhY2NvdW50X2lkIjoiMzMyY2RiODRiOTJhZDExODFhMTdhOWVkOTBlN2RmYWUiLCJvd25lcl9pZCI6ImJiMjYyZDFhYmRjNDgyYjU5ZWNmM2RmNDQ2NmNkZDg0IiwibWV0aG9kIjoiY2JfdXNlcl9hdXRoIiwiZXhwIjoxNDkzMTUyMDAyfQ.Ju2KaRS9HDiJA9OjeJ-V1C0Ttlj0nE_JjXlNVqoRdDoONk-QhklLNTRNaXCpx_aQfcC0uuOzjmn3gQtIN7twikdKIecJDrsSI8PujfH22ugyc6v5OJt3bNY7JETHbB0aDSBH_5bv8-C_hPWd_uqofD84d70kAC5TBzzUbfteCjwYc0Ta3n3W7qk5--owDWmgDXNkd49F4_gqgtqJ7cRfAoUshJkk22HtafEp9h7eWDSkTKYGoENM-Yy74209BIi4U6BAHxwzjm8m0cJGLqdYTFTuFpdC0kFIG16dZEuV-7a_7ZSb3tstt5y5d9mRcSvaj3PmN0h5y_jH6J2QFjrjtQ\"}">>
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_util:184 (<0.21885.994>) undefined content type when getting req data, assuming application/json
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_util:264 (<0.21885.994>) request json is empty
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_util:752 (<0.21885.994>) using auth token found
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.init
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:151 (<0.21885.994>) GET: /v2/accounts/100000000001/channels?auth_token=eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6ImM0NzgyNjRhNmUzZmRlZDVjYzg3MTQ3ZTZhOWY4YWNlIn0.eyJpc3MiOiJrYXpvbyIsImlkZW50aXR5X3NpZyI6IlhhbFZKWUdISll4eTdYX1o4RVAwX1RaNnRCaWdyUXVvSVpEMU83a3FPVVEiLCJhY2NvdW50X2lkIjoiMzMyY2RiODRiOTJhZDExODFhMTdhOWVkOTBlN2RmYWUiLCJvd25lcl9pZCI6ImJiMjYyZDFhYmRjNDgyYjU5ZWNmM2RmNDQ2NmNkZDg0IiwibWV0aG9kIjoiY2JfdXNlcl9hdXRoIiwiZXhwIjoxNDkzMTUyMDAyfQ.Ju2KaRS9HDiJA9OjeJ-V1C0Ttlj0nE_JjXlNVqoRdDoONk-QhklLNTRNaXCpx_aQfcC0uuOzjmn3gQtIN7twikdKIecJDrsSI8PujfH22ugyc6v5OJt3bNY7JETHbB0aDSBH_5bv8-C_hPWd_uqofD84d70kAC5TBzzUbfteCjwYc0Ta3n3W7qk5--owDWmgDXNkd49F4_gqgtqJ7cRfAoUshJkk22HtafEp9h7eWDSkTKYGoENM-Yy74209BIi4U6BAHxwzjm8m0cJGLqdYTFTuFpdC0kFIG16dZEuV-7a_7ZSb3tstt5y5d9mRcSvaj3PmN0h5y_jH6J2QFjrjtQ from 0:0:0:0:0:0:0:1
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:265 (<0.21885.994>) run: known_methods
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:286 (<0.21885.994>) run: allowed_methods
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:71 (<0.21885.994>) mapping v2_resource.allowed_methods.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kazoo_bindings:776 (<0.21885.994>) matched [<<"channels">>,<<"allowed_methods">>,<<"*">>] to [<<"channels">>,<<"allowed_methods">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_accounts:1238 (<0.21885.994>) account 100000000001 db exists, setting operating database as account%2F10%2F64%20000002
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:71 (<0.21885.994>) mapping v2_resource.authenticate
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kazoo_bindings:776 (<0.21885.994>) matched [<<"authenticate">>,<<"*">>] to [<<"authenticate">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_modules_util:520 (<0.21885.994>) flat token cost of 1 configured
Apr 25 22:54:21 kazoo 2600hz[1307]: |00000000000|kz_token_bucket:203 (<0.3822.994>) consumed 1, 99 left
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_token_auth:175 (<0.21885.994>) checking auth token
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_auth_keys:135 (<0.21885.994>) public key 'c478264a6e3fded5cc87147e6a9f8ace' fetched from cache
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_auth_jwt:122 (<0.21885.994>) verifying identity
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kazoo_bindings:762 (<0.21885.994>) exact match for v2_resource.authenticate
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:71 (<0.21885.994>) mapping v2_resource.authorize
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kazoo_bindings:776 (<0.21885.994>) matched [<<"authorize">>,<<"*">>] to [<<"authorize">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_context:250 (<0.21885.994>) checking for superduper admin: 300000000003
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_context:255 (<0.21885.994>) the requestor is a superduper admin
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_simple_authz:147 (<0.21885.994>) authorizing, the request does not contain any system administration modules
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_simple_authz:66 (<0.21885.994>) authorizing the request
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kazoo_bindings:762 (<0.21885.994>) exact match for v2_resource.authorize
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:71 (<0.21885.994>) mapping v2_resource.authorize.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:456 (<0.21885.994>) run: content_types_provided
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.content_types_provided.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:569 (<0.21885.994>) run: languages_provided
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.languages_provided.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:597 (<0.21885.994>) run: resource_exists
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:71 (<0.21885.994>) mapping v2_resource.resource_exists.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kazoo_bindings:776 (<0.21885.994>) matched [<<"channels">>,<<"resource_exists">>,<<"*">>] to [<<"channels">>,<<"resource_exists">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:609 (<0.21885.994>) requested resource exists, validating it
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.validate_resource.accounts
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_accounts:1238 (<0.21885.994>) account 100000000001 db exists, setting operating database as account%2F10%2F64%20000002
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.validate_resource.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.validate.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|cb_channels:271 (<0.21885.994>) getting account summary
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_amqp_worker:441 (<0.21885.994>) attempting to collect 1 responses from ecallmgr
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.status_req.100000000001) via <0.933.0>
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_amqp_worker:614 (<0.959.0>) published request with msg id c1828db1d07de06b89df27fa83b5bcbf for <0.21885.994>
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|ecallmgr_fs_channels:301 (<0.20570.994>) sending back channel data to kazoo...@kazoo.DOMAIN-<0.959.0>-acd745e6
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_amqp_channel:159 (<0.20570.994>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.959.0>-acd745e6) via <0.1659.0>
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_amqp_worker:798 (<0.959.0>) recv message c1828db1d07de06b89df27fa83b5bcbf
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_amqp_worker:802 (<0.959.0>) responses have apparently met the criteria for the client, returning
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kz_amqp_worker:803 (<0.959.0>) response for msg id c1828db1d07de06b89df27fa83b5bcbf took 7606us to return
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.billing
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_util:1049 (<0.21885.994>) billing returned success
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:615 (<0.21885.994>) requested resource update validated
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.etag
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.expires
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:742 (<0.21885.994>) run: to_json
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:84 (<0.21885.994>) folding v2_resource.to_json.get.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|api_resource:232 (<0.21885.994>) GET request fulfilled in 13 ms 118K360B mem 101K322B bin
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|crossbar_bindings:71 (<0.21445.994>) mapping v2_resource.finish_request.GET.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |c1828db1d07de06b89df27fa83b5bcbf|kazoo_bindings:776 (<0.21445.994>) matched [<<"*">>,<<"*">>,<<"finish_request">>,<<"*">>] to [<<"channels">>,<<"GET">>,<<"finish_request">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |0000000000|crossbar_init:40 (<0.25559.994>) routing to version 2
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_util:198 (<0.25559.994>) application/json content type when getting req data
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_util:511 (<0.25559.994>) request has a json payload: { "data": { "action": "transfer", "target": "+3589999999" } }
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_util:269 (<0.25559.994>) request json is valid
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_util:759 (<0.25559.994>) using auth token from header
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.init
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:151 (<0.25559.994>) POST: /v2/accounts/100000000001/channels/0000265500002510000062ed00001f03%40SBC_IN? from 0:0:0:0:0:0:0:1
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:265 (<0.25559.994>) run: known_methods
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:286 (<0.25559.994>) run: allowed_methods
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:71 (<0.25559.994>) mapping v2_resource.allowed_methods.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:776 (<0.25559.994>) matched [<<"channels">>,<<"allowed_methods">>,<<"*">>] to [<<"channels">>,<<"allowed_methods">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_accounts:1238 (<0.25559.994>) account 100000000001 db exists, setting operating database as account%2F10%2F64%20000002
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:71 (<0.25559.994>) mapping v2_resource.authenticate
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:776 (<0.25559.994>) matched [<<"authenticate">>,<<"*">>] to [<<"authenticate">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_modules_util:520 (<0.25559.994>) flat token cost of 1 configured
Apr 25 22:54:21 kazoo 2600hz[1307]: |00000000000|kz_token_bucket:203 (<0.3822.994>) consumed 1, 98 left
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_token_auth:175 (<0.25559.994>) checking auth token
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kz_auth_keys:135 (<0.25559.994>) public key 'c478264a6e3fded5cc87147e6a9f8ace' fetched from cache
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kz_auth_jwt:122 (<0.25559.994>) verifying identity
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:762 (<0.25559.994>) exact match for v2_resource.authenticate
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:71 (<0.25559.994>) mapping v2_resource.authorize
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:776 (<0.25559.994>) matched [<<"authorize">>,<<"*">>] to [<<"authorize">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_context:250 (<0.25559.994>) checking for superduper admin: 300000000003
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_context:255 (<0.25559.994>) the requestor is a superduper admin
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_simple_authz:147 (<0.25559.994>) authorizing, the request does not contain any system administration modules
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_simple_authz:66 (<0.25559.994>) authorizing the request
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:762 (<0.25559.994>) exact match for v2_resource.authorize
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:71 (<0.25559.994>) mapping v2_resource.authorize.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.content_types_accepted.accounts
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.content_types_accepted.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_util:931 (<0.25559.994>) is <<"application/json">> acceptable content type: true
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:456 (<0.25559.994>) run: content_types_provided
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.content_types_provided.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:708 (<0.25559.994>) undefined function cb_channels:content_types_provided/2
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:569 (<0.25559.994>) run: languages_provided
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.languages_provided.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:597 (<0.25559.994>) run: resource_exists
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:71 (<0.25559.994>) mapping v2_resource.resource_exists.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:776 (<0.25559.994>) matched [<<"channels">>,<<"resource_exists">>,<<"*">>] to [<<"channels">>,<<"resource_exists">>,<<"v2_resource">>]
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:609 (<0.25559.994>) requested resource exists, validating it
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.validate_resource.accounts
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_accounts:1238 (<0.25559.994>) account 100000000001 db exists, setting operating database as account%2F10%2F64%20000002
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.validate_resource.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.validate.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kz_amqp_worker:468 (<0.25559.994>) attempting to collect 1 responses from ecallmgr or the first valid
Apr 25 22:54:21 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.959.0>) published to callevt(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key call.status_req.channels) via <0.933.0>
Apr 25 22:54:21 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:614 (<0.959.0>) published request with msg id 4071ba6d54e86260 for <0.25559.994>
Apr 25 22:54:21 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.19423.994>) published to targeted(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key kazoo...@kazoo.DOMAIN-<0.959.0>-acd745e6) via <0.1659.0>
Apr 25 22:54:21 kazoo 2600hz[1307]: |4071ba6d54e86260|kz_amqp_worker:798 (<0.959.0>) recv message 4071ba6d54e86260
Apr 25 22:54:21 kazoo 2600hz[1307]: |4071ba6d54e86260|kz_amqp_worker:802 (<0.959.0>) responses have apparently met the criteria for the client, returning
Apr 25 22:54:21 kazoo 2600hz[1307]: |4071ba6d54e86260|kz_amqp_worker:803 (<0.959.0>) response for msg id 4071ba6d54e86260 took 1195us to return
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|cb_channels:480 (<0.25559.994>) attempting blind transfer 2259313c-d46a-4f92-8e53-7303d22a6952 to +3589999999 by 0000265500002510000062ed00001f03@SBC_IN
Apr 25 22:54:21 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_channel:159 (<0.959.0>) published to metaflow(amqp://guest:gu...@127.0.0.1:5672) exchange (routing key metaflow.action.0000265500002510000062ed00001f03%40SBC_IN.transfer) via <0.933.0>
Apr 25 22:54:21 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|kz_amqp_worker:663 (<0.959.0>) published message b2320f579742d48f for <0.25559.994>
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.billing
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_util:1049 (<0.25559.994>) billing returned success
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:615 (<0.25559.994>) requested resource update validated
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:485 (<0.25559.994>) run: content_types_accepted
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.content_types_accepted.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:503 (<0.25559.994>) checking content type '{<<"application">>,<<"json">>,[]}' against accepted
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:543 (<0.25559.994>) cta: [{{<<"application">>,<<"json">>,[]},from_json}]
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:692 (<0.25559.994>) run: from_json
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:84 (<0.25559.994>) folding v2_resource.execute.post.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:71 (<0.25559.994>) mapping v2_resource.from_json
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|api_resource:232 (<0.25559.994>) POST request fulfilled in 13 ms 40B mem 834B bin
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|crossbar_bindings:71 (<0.4532.994>) mapping v2_resource.finish_request.POST.channels
Apr 25 22:54:21 kazoo 2600hz[1307]: |72c40fb078e4ae768e5b53d91460899f|kazoo_bindings:776 (<0.4532.994>) matched [<<"*">>,<<"*">>,<<"finish_request">>,<<"*">>] to [<<"channels">>,<<"POST">>,<<"finish_request">>,<<"v2_resource">>]
Apr 25 22:54:22 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|ecallmgr_call_events:546 (<0.15925.994>) goodbye and thanks for all the fish: normal
Apr 25 22:54:22 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|kz_amqp_channel:95 (<0.15925.994>) release consumer <0.15925.994> channel assignment
Apr 25 22:54:22 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:893 (<0.138.0>) unregistered handlers for channel <0.7532.994>
Apr 25 22:54:22 kazoo 2600hz[1307]: |5e16a86d-e0ed-4e24-a51f-fca799fa49e2|gen_listener:721 (<0.15925.994>) ecallmgr_call_events terminated cleanly, going down
Apr 25 22:54:22 kazoo 2600hz[1307]: |kz_amqp_history|kz_amqp_history:301 (<0.139.0>) removing AMQP history for consumer <0.15925.994> in 2.5s: normal
Apr 25 22:54:22 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_channel:105 (<0.138.0>) closed amqp channel <0.7532.994>
Apr 25 22:54:22 kazoo 2600hz[1307]: |kz_amqp_assignments|kz_amqp_assignments:300 (<0.138.0>) removed assignment for consumer <0.15925.994>

[Mikko]

I’m trying to work backwards from the code and find the spot that causes the failure.
I'm assuming that I am missing a definition or database entry that causes konami to ignore the transfer attempt.
I’d greatly appreciate it if someone would answer a few specific questions that I am stuck on?

1. The konami app should make a channel-specific binding for the metaflow.action.xxx.xxx routing_key when the channel is formed?

2. This metaflow.action routing_key binding happens after the “{"Listen-On":"self","Endpoint-ID":" ….“  message is sent to konami through rabbitmq?

3. Are the following lines normal or are they possibly the cause of the failure?

Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|reg_authn_req:280 (<0.15296.994>) looking up IP: SBC1 in db sip_auth
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|reg_route_req:49 (<0.15296.994>) failed to find account information from IP SBC1, not replaying route req
Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|konami_listener:107 (<0.21553.994>) no account id for undefined(undefined) owned by undefined

4. Does this later error message mean that konami will ignore requests to this channel?

Apr 25 22:54:08 kazoo 2600hz[1307]: |0000265500002510000062ed00001f03@SBC_IN|konami_listener:115 (<0.14233.994>) unhandled channel for account 100000000001: undefined(resource) owned by undefined

5. The IP of our SBC is in the offnet database. Should we also have an account that matches this IP?

6. What is “routing key konami.transferred.xxx” ?
It appears to be bound at the beginning of the call and unbound on hangup.

Apr 25 22:54:09 kazoo 2600hz[1307]: |21147deb-d0a5-48e0-802f-64ea2f8c7ff4|kz_amqp_channel:321 (<0.24690.985>) bound kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac to kapps exchange (routing key konami.transferred.5e16a86d-e0ed-4e24-a51f-fca799fa49e2) via channel <0.19559.985>

[Mikko]

Progress in baby steps!
I ran sup kapps_maintenance refresh system_schemas and now I’m getting the correct routing keys.

Here are my bindings when no calls are in progress:
rabbitmqadmin list bindings | egrep -i "metaflow|konami| routing_key |----------------"
+-----------------+-------------------------------------------------+---------------------------------------------------------+
|     source      |                   destination                   |                       routing_key                       |
+-----------------+-------------------------------------------------+---------------------------------------------------------+

|                 | konami_listener                                 | konami_listener                                         |
| callmgr         | konami_listener                                 | route.req.*.*                                           |
| callmgr         | konami_listener                                 | route.req.*.*.*                                         |

| metaflow        | konami_listener                                 | metaflow.bind.*.*                                       |
+-----------------+-------------------------------------------------+---------------------------------------------------------+

After starting a call:
+-----------------+-------------------------------------------------+---------------------------------------------------------+
|     source      |                   destination                   |                       routing_key                       |
+-----------------+-------------------------------------------------+---------------------------------------------------------+

|                 | konami_listener                                 | konami_listener                                         |
| callmgr         | konami_listener                                 | route.req.*.*                                           |
| callmgr         | konami_listener                                 | route.req.*.*.*                                         |

| kapps           | kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac  | konami.transferred.0307a3d1-970e-40c8-8e67-c10b0228c204 |
| metaflow        | kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac  | metaflow.action.0307a3d1-970e-40c8-8e67-c10b0228c204.*  |
| metaflow        | kazoo...@kazoo.DOMAIN-<0.24690.985>-8579a2ac  | metaflow.action.c303770b-1133-41a6-8c39-0c3afd78f08f.*  |
| metaflow        | konami_listener                                 | metaflow.bind.*.*                                       |
+-----------------+-------------------------------------------------+---------------------------------------------------------+

I’m now even more confused. Rabbitmqadmin tells me that the transfer request is going to destination kazoo_apps and not konami_listener as I had assumed.
Where in the code should I look for the consumer of these messages?

And I still don’t understand what is the konami.transferred.xxx binding?
The only reference to it is in kapi_konami.erl and I can’t find the application that calls it or the publish_transferred function.

[Te Matau]

What version is this?

[Te Matau]

Have you tried the channels API? Since that theoretically allows a call to be transferred it should give you some clues regarding Konami. We're about to start testing all this on 4.1 so will have some feedback in the next week or so.

[Mikko]

Hi Te,

Great that you joined in. This thread was starting to feel like a one man rant.

>What version is this?

Kazoo status shows 4.0.0.

We’ve installed and updated Kazoo from git. The last local git log entry is on the 5^th of February 2017.

>Have you tried the channels API? Since that theoretically allows a call to be transferred it should give you some clues regarding Konami.

This is exactly how we are trying to transfer the call.

The ability to transfer a call using DTMF would be a nice feature, but if it never works we really don’t care.

The application we are working on can only send the transfer request programmatically, so our only options are the API and injecting a REFER into kamailio.

It seams that the REFER message and the API use different code to transfer the call since REFER works perfectly.

Anyway, I’d like to first exhaust the API option before doing an unconventional hack.

>We're about to start testing all this on 4.1 so will have some feedback in the next week or so

Good to here that. I’m keeping my fingers crossed that a bug was fixed or something else has changed and now it works.

Attached is the script I use to initiate the transfer.

The script queries the channels of the hardcoded account and selects the first channel for transfer.

You have to install resty and jq to use the script.

The transfer target is hardcoded into the script. The auth token is either passed as an argument to the script or define it as an environment variable named AUTH_TOKEN.

[Te Matau]

We've successfully tested the channels API on 4.1. Specifically transfer, hangup works. This did not work in our testing of 4.0. Can you upgrade and try again?

What I think of as Konami (using DTMF codes to transfer, start call recording etc) does not work in 4.1. This is a blocker for us so we're going to need to find a way around that before we upgrade.

[Mikko]

Thanks! That’s great news for us. I’ll do the update this week and report back if it worked or not.

What I think of as Konami (using DTMF codes to transfer, start call recording etc) does not work in 4.1. This is a blocker for us so we're going to need to find a way around that before we upgrade.

After the update, I’ll test if DTMF transfer works on our install. There's a small chance that I have inadvertently fixed something by playing with the confs.

[Te Matau]

Konami (DTMF) also works for us in 4.1.

[Marcin Muzylo]

yes, Transfer by API or DTMF works in 4.1

[Yuriy Nasida]

Yes, I also got it working at 4.1

--
You received this message because you are subscribed to the Google Groups "2600hz-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to 2600hz-dev+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Mikko]

Thanks Te, Marcin and Yuriy for confirming that it works in 4.1.

I upgraded to 4.1.7 and now it works for part of our call cases.
When I call in from the PSTN to a sip extension, DTMF transfer/hangup and channels API transfer work perfectly.

I’m still unable to transfer a call when the extension is a GSM number.
In these calls, I’m briefly seeing the correct routing_keys (call.DTMF.xxx and metaflow.action.xxx.*), but they disappear when the GSM starts ringing.
Nevertheless, now I feel like I’m light-years closer to getting it to work with all call cases. Thanks!

On Friday, May 12, 2017 at 6:53:05 PM UTC+3, Yuriy Nasida wrote:

Yes, I also got it working at 4.1

On 11 May 2017 at 15:47, Marcin Muzylo <bi...@ipvoice.pl> wrote:

yes, Transfer by API or DTMF works in 4.1

W dniu środa, 10 maja 2017 20:18:51 UTC+2 użytkownik Te Matau napisał:

Konami (DTMF) also works for us in 4.1.

--
You received this message because you are subscribed to the Google Groups "2600hz-dev" group.

To unsubscribe from this group and stop receiving emails from it, send an email to 2600hz-dev+...@googlegroups.com.