Terminating Call too early

bsimpson72515 · January 7, 2020

We are having an issue with Kazoo. After the private pin is entered in during any phone call the call terminates. What our systems engineer thinks is this could be a backwards compatibility issue. We are using a newer version of Kazoo with an older web service.

Below is what the logs say. Any idea why this is terminating? Any help on this would be appreciated.

Jan 7 16:05:52 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_receiver:135(<0.2516.0>) finish key '#' pressed
Jan 7 16:05:52 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_twiml:341(<0.2516.0>) caller entered DTMFs: 77649

Jan 7 16:05:52 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:431(<0.2507.0>) sending req to http://209.142.178.205:57113/Keefe_2//keefe/PINentered(post): Digits=77649&CallerNumber=9940140000&CallerName=9940140000&Direction=inbound&ApiVersion=2010-04-01&ToRealm=165.227.107.0&To=9940140000&FromRealm=165.227.107.0&From=9940140000&AccountSid=72bd25b60a91cfebe5bf1f50894126ee&CallSid=call-711CE674-8013-3810-000C-2F%4072.82.244.65

Jan 7 16:05:53 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:292(<0.2507.0>) adding response chunk: '<?xml version="1.0" encoding="UTF-8"?>#015#012<Response>#015#012<Gather timeout="8" numDigits="11" method="POST" action="http://209.142.178.205:57113/Keefe_2//keefe/PINTWOentered?pin2=1329">#015#012<Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/db76b3bc7dc1b656761f2f760147a5f1/uploaded_file_63717919486.wav</Play>#015#012</Gather>#015#012<Redirect method="GET">http://209.142.178.205:57113/Keefe_2//keefe/TimedOut?redirect=welcome</Redirect>#015#012</Response>'

Jan 7 16:05:53 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:478(<0.2657.0>) finding translator for content type text/xml; charset=utf-8
Jan 7 16:05:53 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_twiml:291(<0.2657.0>) GATHER: exec sub actions
Jan 7 16:05:53 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_twiml:233(<0.2658.0>) PLAY 'http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/db76b3bc7dc1b656761f2f760147a5f1/uploade$$ploaded_file_63717919486.wav'
Jan 7 16:05:53 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2664.0>) ignoring event CHANNEL_EXECUTE_COMPLETE
Jan 7 16:05:53 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2665.0>) ignoring event CHANNEL_EXECUTE_COMPLETE
Jan 7 16:05:54 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2667.0>) ignoring event DTMF
Jan 7 16:05:54 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_receiver:144(<0.2657.0>) first dtmf pressed: 1
Jan 7 16:05:54 pintransfer 2600hz[1137]: |kz_amqp_assignments|kz_amqp_assignments:896(<0.190.0>) short lived assignment (1s) for <0.2658.0> (channel <0.2330.0> type float broker <<"amqp://guest:guest@127.0.0.1:5672">>)
Jan 7 16:05:54 pintransfer 2600hz[1137]: |0000000000|Undefined:Undefined(<0.2330.0>) Channel (<0.2330.0>): Unregistering return handler <0.2658.0> because it died. Reason: killed
Jan 7 16:05:54 pintransfer 2600hz[1137]: |0000000000|Undefined:Undefined(<0.2330.0>) Channel (<0.2330.0>): Unregistering confirm handler <0.2658.0> because it died. Reason: killed
Jan 7 16:05:54 pintransfer 2600hz[1137]: |0000000000|Undefined:Undefined(<0.2330.0>) Channel (<0.2330.0>): Unregistering flow handler <0.2658.0> because it died. Reason: killed
Jan 7 16:05:54 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2668.0>) ignoring event CHANNEL_EXECUTE_COMPLETE
Jan 7 16:05:54 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2669.0>) ignoring event CHANNEL_EXECUTE_COMPLETE
Jan 7 16:05:54 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2671.0>) ignoring event DTMF
Jan 7 16:05:54 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2672.0>) ignoring event DTMF
Jan 7 16:05:55 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2675.0>) ignoring event DTMF
Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2676.0>) ignoring event DTMF
Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_receiver:135(<0.2657.0>) finish key '#' pressed
Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_twiml:341(<0.2657.0>) caller entered DTMFs: 1329

Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:431(<0.2507.0>) sending req to http://209.142.178.205:57113/Keefe_2//keefe/PINTWOentered?pin2=1329(post): Digits=1329&CallerNumber=9940140000&CallerName=9940140000&Direction=inbound&ApiVersion=2010-04-01&ToRealm=165.227.107.0&To=9940140000&FromRealm=165.227.107.0&From=9940140000&AccountSid=72bd25b60a91cfebe5bf1f50894126ee&CallSid=call-711CE674-8013-3810-000C-2F%4072.82.244.65

Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:292(<0.2507.0>) adding response chunk: '<?xml version="1.0" encoding="UTF-8" ?><Response><Gather timeout="3" method="POST" numDigits="1" finishOnKey="*" action="http://209.142.178.205:57113/Keefe_2//Keefe/amountEntered"><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/0ba148c6d41ce65a83d55ec6f55a0cfe/uploaded_file_63717918365.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/d24bce752b221dba5e102b2e62a61de2/uploaded_file_63717920085.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/0e42a32458483ecc434bee0fd2f996e6/uploaded_file_63717919777.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/32ac4a81fa6f38b5b890c00b43ad1fbb/uploaded_file_63717919709.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/0b45988cae9162ec2beb87c574d368d0/uploaded_file_63717919834.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/d424d2a88d57a2f93997ae1e9e3eb5e4/uploaded_file_63717921528.wav</Play>;<Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/2cbefd504d68b9a1fcc70ca48c92f74b/uploaded_file_63717919608.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/2176d057b10d601bd45678f0fb1a221b/uploaded_file_63717919623.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/e4478ccceaa4473e95a78133add0a2a9/uploaded_file_63717919584.wav</Play>;<Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/65109536d1ed3291e64121e28d8921c3/uploaded_file_63717919523.wav</Play></Gather><Redirect method="GET">http://209.142.178.205:57113/Keefe_2//keefe/TimedOut?redirect=purchase</Redirect></Response>'

Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:478(<0.2677.0>) finding translator for content type text/xml; charset=utf-8
Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_twiml:291(<0.2677.0>) GATHER: exec sub actions
Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_twiml:233(<0.2678.0>) PLAY 'http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/0ba148c6d41ce65a83d55ec6f55a0cfe/uploade$$ploaded_file_63717918365.wav'
Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2684.0>) ignoring event CHANNEL_EXECUTE_COMPLETE
Jan 7 16:05:56 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2685.0>) ignoring event CHANNEL_EXECUTE_COMPLETE
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2691.0>) ignoring event DTMF
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_receiver:322(<0.2678.0>) adding dtmf tone '1' to collection
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_receiver:144(<0.2677.0>) first dtmf pressed: 1
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|kzt_twiml:341(<0.2677.0>) caller entered DTMFs: 1
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2692.0>) ignoring event CHANNEL_EXECUTE_COMPLETE
Jan 7 16:05:57 pintransfer 2600hz[1137]: |kz_amqp_assignments|kz_amqp_assignments:896(<0.190.0>) short lived assignment (1s) for <0.2678.0> (channel <0.2336.0> type float broker <<"amqp://guest:guest@127.0.0.1:5672">>)

Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:431(<0.2507.0>) sending req to http://209.142.178.205:57113/Keefe_2//Keefe/amountEntered(post): Digits=1&CallerNumber=9940140000&CallerName=9940140000&Direction=inbound&ApiVersion=2010-04-01&ToRealm=165.227.107.0&To=9940140000&FromRealm=165.227.107.0&From=9940140000&AccountSid=72bd25b60a91cfebe5bf1f50894126ee&CallSid=call-711CE674-8013-3810-000C-2F%4072.82.244.65

Jan 7 16:05:57 pintransfer 2600hz[1137]: |0000000000|Undefined:Undefined(<0.2336.0>) Channel (<0.2336.0>): Unregistering return handler <0.2678.0> because it died. Reason: killed
Jan 7 16:05:57 pintransfer 2600hz[1137]: |0000000000|Undefined:Undefined(<0.2336.0>) Channel (<0.2336.0>): Unregistering confirm handler <0.2678.0> because it died. Reason: killed
Jan 7 16:05:57 pintransfer 2600hz[1137]: |0000000000|Undefined:Undefined(<0.2336.0>) Channel (<0.2336.0>): Unregistering flow handler <0.2678.0> because it died. Reason: killed
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:121(<0.2693.0>) ignoring event CHANNEL_EXECUTE_COMPLETE

Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:292(<0.2507.0>) adding response chunk: '<?xml version="1.0" encoding="UTF-8" ?>#015#012<Response>#015#012 <Gather numDigits="1" timeout="8" action="http://209.142.178.205:57113/Keefe_2//Keefe/Confirmed" finishOnKey="*">#015#012 <Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/ffc1defb47e4e09995e85013e9ae66d5/uploaded_file_63717918334.wav</Play>#015#012 <Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/a0777b73a4d684b5b03fbd5cda74382c/uploaded_file_63717919723.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/d424d2a88d57a2f93997ae1e9e3eb5e4/uploaded_file_63717921528.wav</Play>;#015#012 <Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/1e3719e4105bd7c2b64ab07969e8c053/uploaded_file_63717918320.wav</Play>#015#012 </Gather>#015#012 <Redirect method="GET">http://209.142.178.205:57113/Keefe_2//keefe/TimedOut?redirect=confirm</Redirect>#015#012</Response>'

Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:478(<0.2694.0>) finding translator for content type text/html; charset=utf-8
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:392(<0.2507.0>) pivot call terminating: normal
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|cf_exe:468(<0.2496.0>) recv channel destroyed, going down
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|cf_exe:676(<0.2496.0>) callflow execution has been stopped: normal

Edited January 7, 2020 by bsimpson72515
Clarification (see edit history)

bsimpson72515 · January 7, 2020

This is happening on every call not just one.

lazedo · January 8, 2020

4 hours ago, bsimpson72515 said:

We are using a newer version of Kazoo with an older web service

please, be more specific.

4 hours ago, bsimpson72515 said:

<Redirect method="GET">http://209.142.178.205:57113/Keefe_2//keefe/TimedOut?redirect=confirm</Redirect>#015#012</Response>'

Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:478(<0.2694.0>) finding translator for content type text/html; charset=utf-8
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:392(<0.2507.0>) pivot call terminating: normal

looks like your redirect action is returning text/html ?

bsimpson72515 · January 8, 2020

@lazedo In 2016 Lattice wrote a web service program to control the actions of IVR. The IVR was built on CENTOS 6.6 and kazoo UI was used to configure the call flow. The new IVR is using CENTOS 7 and monster UI to configure call flow.

They both use text/html to communicate to the web service. Here is a return example when you put the pivot URL in a browser:
I attached that return example

lazedo · January 9, 2020

mc_ · January 9, 2020

@bsimpson72515 the previous Pivot requests to your URLs all returned with 'Content-Type: text/xml'. 'text/xml' is associated with the twiml backend of Pivot and so life is good. The errant response itself is fine, XML-wise, but the server is returning 'Content-Type: text/html' which is not associated with any Pivot backend. Why does the web server response with the proper Content-Type header in all but the last response?

bsimpson72515 · January 9, 2020

Hey @mc_ just for clarification our systems engineer asked if this at the top was the part you were asking about? Or is it the one at the bottom?

Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:478(<0.2694.0>) finding translator for content type text/html; charset=utf-8
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:392(<0.2507.0>) pivot call terminating: normal
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|cf_exe:468(<0.2496.0>) recv channel destroyed, going down
Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|cf_exe:676(<0.2496.0>) callflow execution has been stopped: normal

Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:292(<0.2507.0>) adding response chunk: '<?xml version="1.0" encoding="UTF-8" ?>#015#012<Response>#015#012 <Gather numDigits="1" timeout="8" action="http://209.142.178.205:57113/Keefe_2//Keefe/Confirmed" finishOnKey="*">#015#012 <Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/ffc1defb47e4e09995e85013e9ae66d5/uploaded_file_63717918334.wav</Play>#015#012 <Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/a0777b73a4d684b5b03fbd5cda74382c/uploaded_file_63717919723.wav</Play><Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/d424d2a88d57a2f93997ae1e9e3eb5e4/uploaded_file_63717921528.wav</Play>;#015#012 <Play>http://65.112.209.240:5984/account%2F02%2Fd2%2F92c7b081a86a100ef907bef67f61/1e3719e4105bd7c2b64ab07969e8c053/uploaded_file_63717918320.wav</Play>#015#012 </Gather>#015#012 <Redirect method="GET">http://209.142.178.205:57113/Keefe_2//keefe/TimedOut?redirect=confirm</Redirect>#015#012</Response>'

mc_ · January 9, 2020

Pivot posted to ' Jan 7 16:05:57 pintransfer 2600hz[1137]: |call-711CE674-8013-3810-000C-2F@72.82.244.65|pivot_call:431(<0.2507.0>) sending req to http://209.142.178.205:57113/Keefe_2//Keefe/amountEntered(post): Digits=1&CallerNumber=9940140000&CallerName=9940140000&Direction=inbound&ApiVersion=2010-04-01&ToRealm=165.227.107.0&To=9940140000&FromRealm=165.227.107.0&From=9940140000&AccountSid=72bd25b60a91cfebe5bf1f50894126ee&CallSid=call-711CE674-8013-3810-000C-2F%4072.82.244.65 '

That returned text/html which is wrong, it should be text/xml, as the previous responses returned.

bsimpson72515 · January 9, 2020

Okay we'll definitely look into this. I had a few questions though. We had a working kazoo installation on another server and it was using CENTOS 6.6 and an older version of Kazoo as well the response type it gave on its final pivot request was text/html as well. I was wondering could this working still with that response type be due to it being the older versions of Centos and Kazoo. Or is this unrelated? We are using a newer version of Centos and Kazoo now though of course so how can we get it to do text/xml instead of text/html response type?

mc_ · January 9, 2020

The first implementation of Pivot was a basic TwiML clone, so we probably didn't check the content-type response header then. When we added KAZOO's callflow JSON as an option, Pivot started checking the content-type to know which backend, kzt_twiml or kzt_kazoo, to use interpreting the response.

Now, why your server changes from text/xml to text/html I can't answer. Its obvious the preceding responses had their content-type header set to text/xml so you would need to check the code path taken on your side for this failing response to see why it didn't set the content-type header.

bsimpson72515 · January 13, 2020

This is from our Systems Engineer

Did they say if there was a way to install the older version from 2016 (before the JSON option)?

I’m not sure why the server changes from xml to html. It’s probable a bug that didn’t matter with the older install…

mc_ · January 13, 2020

I mean, its your cluster right? So you can run whatever you want. But, IMHO, how is running a 4+ year old version of KAZOO easier than fixing on HTTP response's content-type header?

bsimpson72515 · January 13, 2020

So bad news apparently we do not have the source code for our cluster. I guess that is why he was asking about the other version.

lazedo · January 14, 2020

you can always go back to the kazoo version that worked for you. the source code is in github.

bsimpson72515 · January 17, 2020

Do you know what the last version was before they depricated kazoo ui in favor of monster ui?

mc_ · January 17, 2020

@bsimpson72515 afaik kazoo-ui will still work through 4.3. When 5.0 is release, /v1 of the API will be deprecated and kazoo-ui will cease to work as it uses /v1.

bsimpson72515 · January 17, 2020

So would you recommend I just avoid installing monster ui and use kazoo ui or is there a good path to get to kazoo ui in centos after installing kazoo?

Or is there anything we need to install to get kazoo ui working instead of monster ui?

Terminating Call too early

Recommended Posts

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Join the conversation