onnet trunkstore troubleshooting
222 views
Skip to first unread message
Zhen
Oct 25, 2015, 5:57:26 PM10/25/15
to 2600hz-dev
Hello,
My first post, first wanted to say I looove kazoo, and I can't express how grateful I am, big thank you!
I'm playing with trunkstore/pbx connector. Two accounts: one *8f8f with trunkstore DID ++12265551111; the other one with regular smartpbx softphone. I tried calling from softphone, but call is not routing out. I can see it found the DID, even says "call began on the network", but I tshark on the remote end, no packets. Later it says "request is not for a trunkstore account"... Seemed it went on to try callflow, hit no_match, then timeout...
Questions:
1) what is the normal hunt sequence, try trunkstore first, then callflow?
2) for account with pbx connector configured, is it normal for ts_callflow to "say request is not for a trunkstore account"?
3) maybe shed some light on how to debug further? :)
----
wnm_number:1243 (<0.2963.0>) loaded phone_numbers from aac8fb75e5139aa23da19975d0aa8f8f
...
ts_route_req:24 (<0.3134.0>) received a request asking if trunkstore can route this call
ts_route_req:35 (<0.3134.0>) call began on the network
cf_route_req:30 (<0.3135.0>) received a request asking if callflows can route this call
cf_util:623 (<0.3135.0>) searching for callflow in account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f to satisfy '+12265551111'
ts_callflow:52 (<0.3139.0>) request is not for a trunkstore account
milliwatt_route_req:39 (<0.3137.0>) milliwatt does not know what to do with this!
cf_util:672 (<0.3135.0>) lookup callflow patterns for +12265551111 in account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f
cf_util:623 (<0.3135.0>) searching for callflow in account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f to satisfy 'no_match'
cf_route_req:38 (<0.3135.0>) only available callflow is a nomatch for a unauthorized call
Oct 25 21:14:07 newitsp 2600hz[6049]: |3e9e7875818f3c2593f8d3746590782d@0:0:0:0:0:0:0:0|ecallmgr_fs_route:271 (<0.1960.0>) did not receive route response for request 523c76e0-7b5d-11e5-8361-31c8e673257d: timeout
-----
https://github.com/2600hz/kazoo/blob/master/applications/trunkstore/src/ts_route_req.erl
{AcctID, AuthID} when is_binary(AcctID) andalso is_binary(AuthID) ->
%% Coming from PBX (on-net); authed by Registrar or ts_auth
line 35 lager:info("call began on the network"),
ts_onnet_sup:start_handler(<<"onnet-", CallID/binary>>, ApiJObj);
-----
full debug log in:
http://pastebin.com/Zp8zxzR6
-----
Version : master-203 - R15B03
-----
{
"_id": "334f758bb1256ad4fd4a3f60f711ff45",
"_rev": "4-fde4c3ab5d05dd84750dd485534aaf50",
"account": {
"credits": {
"prepay": "0.00"
},
"trunks": 0,
"inbound_trunks": 0,
"auth_realm": "newitsp1.local"
},
"billing_account_id": "aac8fb75e5139aa23da19975d0aa8f8f",
"DIDs_Unassigned": {
},
"servers": [
{
"DIDs": {
"+12265551111": {
"failover": {
},
"caller_id": {
"cid_name": "James At The Crabshack",
"cid_number": "+12265551111"
},
"force_outbound": false,
"options": [
"CName"
],
"user": "ja...@newitsp1.local",
"provider": "VoIP DIDs 4 You"
}
},
"options": {
"enabled": true,
"inbound_format": "e164",
"international": false,
"caller_id": {
},
"e911_info": {
},
"failover": {
},
"media_handling": "bypass"
},
"permissions": {
"users": [
]
},
"monitor": {
"monitor_enabled": false
},
"server_name": "kazoo.local",
"auth": {
"auth_method": "IP",
"ip": "192.168.1.249",
"auth_user": "user_vvk9vw7v",
"auth_password": "zu4b42btftgh"
},
"server_type": "FreeSWITCH",
"cfg": {
}
}
],
"ui_metadata": {
"version": "master-85",
"ui": "monster-ui",
"origin": "pbxs"
},
"id": "334f758bb1256ad4fd4a3f60f711ff45",
"pvt_is_authenticated": true,
"pvt_auth_account_id": "404bc69da5d072e9f9a67753c3931314",
"pvt_auth_user_id": "cec302ceeec52aeb8755906e729224b7",
"pvt_request_id": "33afbf1f192d92a35b88ef57807f4211",
"pvt_modified": 63613005791,
"pvt_created": 63613005769,
"pvt_account_db": "account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f",
"pvt_account_id": "aac8fb75e5139aa23da19975d0aa8f8f",
"pvt_vsn": "1",
"pvt_type": "sys_info"
}
My first post, first wanted to say I looove kazoo, and I can't express how grateful I am, big thank you!
I'm playing with trunkstore/pbx connector. Two accounts: one *8f8f with trunkstore DID ++12265551111; the other one with regular smartpbx softphone. I tried calling from softphone, but call is not routing out. I can see it found the DID, even says "call began on the network", but I tshark on the remote end, no packets. Later it says "request is not for a trunkstore account"... Seemed it went on to try callflow, hit no_match, then timeout...
Questions:
1) what is the normal hunt sequence, try trunkstore first, then callflow?
2) for account with pbx connector configured, is it normal for ts_callflow to "say request is not for a trunkstore account"?
3) maybe shed some light on how to debug further? :)
----
wnm_number:1243 (<0.2963.0>) loaded phone_numbers from aac8fb75e5139aa23da19975d0aa8f8f
...
ts_route_req:24 (<0.3134.0>) received a request asking if trunkstore can route this call
ts_route_req:35 (<0.3134.0>) call began on the network
cf_route_req:30 (<0.3135.0>) received a request asking if callflows can route this call
cf_util:623 (<0.3135.0>) searching for callflow in account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f to satisfy '+12265551111'
ts_callflow:52 (<0.3139.0>) request is not for a trunkstore account
milliwatt_route_req:39 (<0.3137.0>) milliwatt does not know what to do with this!
cf_util:672 (<0.3135.0>) lookup callflow patterns for +12265551111 in account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f
cf_util:623 (<0.3135.0>) searching for callflow in account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f to satisfy 'no_match'
cf_route_req:38 (<0.3135.0>) only available callflow is a nomatch for a unauthorized call
Oct 25 21:14:07 newitsp 2600hz[6049]: |3e9e7875818f3c2593f8d3746590782d@0:0:0:0:0:0:0:0|ecallmgr_fs_route:271 (<0.1960.0>) did not receive route response for request 523c76e0-7b5d-11e5-8361-31c8e673257d: timeout
-----
https://github.com/2600hz/kazoo/blob/master/applications/trunkstore/src/ts_route_req.erl
{AcctID, AuthID} when is_binary(AcctID) andalso is_binary(AuthID) ->
%% Coming from PBX (on-net); authed by Registrar or ts_auth
line 35 lager:info("call began on the network"),
ts_onnet_sup:start_handler(<<"onnet-", CallID/binary>>, ApiJObj);
-----
full debug log in:
http://pastebin.com/Zp8zxzR6
-----
Version : master-203 - R15B03
-----
{
"_id": "334f758bb1256ad4fd4a3f60f711ff45",
"_rev": "4-fde4c3ab5d05dd84750dd485534aaf50",
"account": {
"credits": {
"prepay": "0.00"
},
"trunks": 0,
"inbound_trunks": 0,
"auth_realm": "newitsp1.local"
},
"billing_account_id": "aac8fb75e5139aa23da19975d0aa8f8f",
"DIDs_Unassigned": {
},
"servers": [
{
"DIDs": {
"+12265551111": {
"failover": {
},
"caller_id": {
"cid_name": "James At The Crabshack",
"cid_number": "+12265551111"
},
"force_outbound": false,
"options": [
"CName"
],
"user": "ja...@newitsp1.local",
"provider": "VoIP DIDs 4 You"
}
},
"options": {
"enabled": true,
"inbound_format": "e164",
"international": false,
"caller_id": {
},
"e911_info": {
},
"failover": {
},
"media_handling": "bypass"
},
"permissions": {
"users": [
]
},
"monitor": {
"monitor_enabled": false
},
"server_name": "kazoo.local",
"auth": {
"auth_method": "IP",
"ip": "192.168.1.249",
"auth_user": "user_vvk9vw7v",
"auth_password": "zu4b42btftgh"
},
"server_type": "FreeSWITCH",
"cfg": {
}
}
],
"ui_metadata": {
"version": "master-85",
"ui": "monster-ui",
"origin": "pbxs"
},
"id": "334f758bb1256ad4fd4a3f60f711ff45",
"pvt_is_authenticated": true,
"pvt_auth_account_id": "404bc69da5d072e9f9a67753c3931314",
"pvt_auth_user_id": "cec302ceeec52aeb8755906e729224b7",
"pvt_request_id": "33afbf1f192d92a35b88ef57807f4211",
"pvt_modified": 63613005791,
"pvt_created": 63613005769,
"pvt_account_db": "account%2Faa%2Fc8%2Ffb75e5139aa23da19975d0aa8f8f",
"pvt_account_id": "aac8fb75e5139aa23da19975d0aa8f8f",
"pvt_vsn": "1",
"pvt_type": "sys_info"
}
James Aimonetti
Oct 25, 2015, 6:20:01 PM10/25/15
to 2600h...@googlegroups.com
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
One thing you may want to try is flush the trunkstore cache:
sup trunkstore_maintenance flush
The DID lookup is cached, and should be flushed automatically when you
make changes to trunkstore documents. If the issue still persists,
please file a ticket so we can investigate this issue more fully.
Thank you for the excellent report.
To answer a couple questions you had:
1. Hunt sequence is in parallel. Trunkstore and callflows run
independent of each other and each receive requests for routing.
However, each route request contains enough information to allow both
apps to determine if they know how to route the leg.
You can see in your full debug log that both receive the a-leg,
trunkstore rightfully sees it can't route the leg and stops its
processing. Callflows meanwhile sees the call is from a known device
to an unknown (to that account) DID and routes it offnet.
You then see stepswitch receive the offnet request from callflows.
Stepswitch has a cluster-wide view of known DIDs and realizes the
requested DID belongs to another account. This causes some commands to
be run (execute_extension) to generate another route request
(basically willing the b-leg into existence then bridging if successful)
.
The logs then show a second round of route request processing;
trunkstore again fails to find the necessary information and stops;
callflows also fails because the caller isn't known to this account,
and the call setup falls apart.
Hope that helps you read what happened a little better.
Again, if flushing doesn't work, something else is amiss (the second
route request doesn't have information that trunkstore can utilize
properly), and we need to fix that ASAP!
James
- --
James Aimonetti
Lead Systems Architect / Impressionable Scallywag
"If Dialyzer doesn't care, I don't care"
2600Hz | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQEcBAEBCAAGBQJWLVWOAAoJENTKa+JPXCVgOawH/RPpn3pkEXoSBQTsnI/OGVN1
sNi8sX1fa+Vj/hjZpI3G8wSvl1vQTb2B9YvqnFRgNOEzIY+4wD4U/fvza7/oSIZd
JpE09ZtERClDE/NEaEdHH76z8k4CA1DGUeUYMxuOQgm2l7baH4hkEfY9FV6wceOG
dveN7ocO7o+1kClYQsu+kGyA8Eyr1XcKIXE6w9bqHntYf0g+wSMNonS9G1mc2H3Z
M0VqOU8bU9iRDD5CvXFx1t1xL6W71UjryE3mm1UjlORdnutELzwhdEnTtnrGXXlT
H+v+lrPnn0RDj+a/LZD4kp/ZHdAUAcsxiE+KaVyNq9FPuoNPDnXFT7G5UGW7emc=
=Dplf
-----END PGP SIGNATURE-----
Hash: SHA256
One thing you may want to try is flush the trunkstore cache:
sup trunkstore_maintenance flush
The DID lookup is cached, and should be flushed automatically when you
make changes to trunkstore documents. If the issue still persists,
please file a ticket so we can investigate this issue more fully.
Thank you for the excellent report.
To answer a couple questions you had:
1. Hunt sequence is in parallel. Trunkstore and callflows run
independent of each other and each receive requests for routing.
However, each route request contains enough information to allow both
apps to determine if they know how to route the leg.
You can see in your full debug log that both receive the a-leg,
trunkstore rightfully sees it can't route the leg and stops its
processing. Callflows meanwhile sees the call is from a known device
to an unknown (to that account) DID and routes it offnet.
You then see stepswitch receive the offnet request from callflows.
Stepswitch has a cluster-wide view of known DIDs and realizes the
requested DID belongs to another account. This causes some commands to
be run (execute_extension) to generate another route request
(basically willing the b-leg into existence then bridging if successful)
.
The logs then show a second round of route request processing;
trunkstore again fails to find the necessary information and stops;
callflows also fails because the caller isn't known to this account,
and the call setup falls apart.
Hope that helps you read what happened a little better.
Again, if flushing doesn't work, something else is amiss (the second
route request doesn't have information that trunkstore can utilize
properly), and we need to fix that ASAP!
James
James Aimonetti
Lead Systems Architect / Impressionable Scallywag
"If Dialyzer doesn't care, I don't care"
2600Hz | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQEcBAEBCAAGBQJWLVWOAAoJENTKa+JPXCVgOawH/RPpn3pkEXoSBQTsnI/OGVN1
sNi8sX1fa+Vj/hjZpI3G8wSvl1vQTb2B9YvqnFRgNOEzIY+4wD4U/fvza7/oSIZd
JpE09ZtERClDE/NEaEdHH76z8k4CA1DGUeUYMxuOQgm2l7baH4hkEfY9FV6wceOG
dveN7ocO7o+1kClYQsu+kGyA8Eyr1XcKIXE6w9bqHntYf0g+wSMNonS9G1mc2H3Z
M0VqOU8bU9iRDD5CvXFx1t1xL6W71UjryE3mm1UjlORdnutELzwhdEnTtnrGXXlT
H+v+lrPnn0RDj+a/LZD4kp/ZHdAUAcsxiE+KaVyNq9FPuoNPDnXFT7G5UGW7emc=
=Dplf
-----END PGP SIGNATURE-----
Zhen
Oct 25, 2015, 7:30:25 PM10/25/15
to 2600hz-dev
Thanks James for the super fast detailed response on Sunday evening! This is not cached DID issue because I even built another server from iso just to test, same result. But I got this working at some point though. So most likely this is not a bug. As mentioned I was just playing with trunkstore, this is NOT production and it is Version : master-203 - R15B03, so no rush at all. I will play with it a bit and will file a ticket if can't figure out. Thanks again!
Zhen
Oct 26, 2015, 10:35:52 AM10/26/15
to 2600hz-dev
VCCS Telecom
Oct 27, 2015, 8:35:07 PM10/27/15
to 2600hz-dev
I had this same debug earlier today. I realized that the REALM value was incorrect in couch (old setting perhaps), it was not reflective of the GUI displayed value which is the actual Account realm.
Matt
Nurango
Reply all
Reply to author
Forward
0 new messages