Jump to content

Callflow not executing hangup

simonp22

By simonp22
in Product Discussion

 Share

Recommended Posts

simonp22

simonp22

Posted
Posted

I have a callflow that simply plays a media and then should hang up the call, however the call is never hanging up. Below are the logs, does anyone have any ideas?

  

Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:632(<0.8280.10>) publishing call event channel_execute_complete 'play(http_cache://http://127.0.0.1:15984/account/93/81/3fae04349906f8341b6331aa295c/c491d65d6968f313e9e479a4f872b295/text_to_speech_63765821791.wav?rev=2-c56b84c29327ea44182935f772745baf)' result: file played
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:579(<0.8282.10>) play finished, checking for group-id/DTMF termination
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:605(<0.8282.10>) media finished playing, advancing control queue
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:1056(<0.8282.10>) executing call command 'noop' f1165a67abe613804204879c0efe6daa
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:252(<0.8280.10>) application ecallmgr checked out worker <0.494.0> from pool kz_amqp_pool
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_channel:245(<0.494.0>) published to callevt(direct 1K) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.262c021a-63ac-1239-9999-0242ac110006) via <0.713.0>
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:737(<0.494.0>) published message 1598603679634566 for <0.8280.10>
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_util:180(<0.8282.10>) execute on node freeswitch@kazoo-test.voip.domain.com(262c021a-63ac-1239-9999-0242ac110006) event(Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=f1165a67abe613804204879c0efe6daa): ok
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:632(<0.8280.10>) publishing call event channel_execute_complete 'noop()' result: f1165a67abe613804204879c0efe6daa
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:551(<0.8282.10>) noop execution complete for f1165a67abe613804204879c0efe6daa, advancing control queue
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:634(<0.8282.10>) no call commands remain queued, hibernating
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:252(<0.8280.10>) application ecallmgr checked out worker <0.478.0> from pool kz_amqp_pool
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_channel:245(<0.478.0>) published to callevt(direct 1K) exchange (routing key call.CHANNEL_EXECUTE_COMPLETE.262c021a-63ac-1239-9999-0242ac110006) via <0.671.0>
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:737(<0.478.0>) published message 1598603679654564 for <0.8280.10>
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|cf_util:669(<0.28168.86>) noop f1165a67abe613804204879c0efe6daa received
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|cf_exe:428(<0.28040.86>) continuing to child '_'
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|cf_exe:764(<0.28040.86>) moving to action 'cf_hangup'
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|cf_exe:599(<0.28040.86>) cf module cf_temporal_route down normally
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_channel:221(<0.28165.86>) published(92a783b720885a321d8eedec0418e7f7 337B) to callctl(amqp://guest:guest@127.0.0.1:5672) exchange (routing key ecallmgr@kazoo-test.voip.domain.com-ecallmgr_call_control-<0.8282.10>-7da520c1) via <0.28592.57>
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|cf_exe:459(<0.28040.86>) instructed to hard_stop
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:252(<0.28040.86>) application callflow checked out worker <0.732.0> from pool kz_amqp_pool
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|gen_listener:1623(<0.8282.10>) new heap size 20688 (delta 121152)
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_channel:245(<0.732.0>) published to callctl(direct 261B) exchange (routing key ecallmgr@kazoo-test.voip.domain.com-ecallmgr_call_control-<0.8282.10>-7da520c1) via <0.1069.0>
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:960(<0.8282.10>) inserting at the tail of the control queue call command hangup
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:737(<0.732.0>) published message ea5a03d62af4efb8 for <0.28040.86>
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:1056(<0.8282.10>) executing call command 'hangup' 92a783b720885a321d8eedec0418e7f7
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|cf_exe:691(<0.28040.86>) callflow execution has been stopped: normal
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_util:148(<0.8282.10>) terminate call on node freeswitch@kazoo-test.voip.domain.com
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:960(<0.8282.10>) inserting at the tail of the control queue call command hangup
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_fs_presence:275(<0.8325.10>) sending presence terminated to 447701234567/441111222333 in realm carrier.com
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:196(<0.8280.10>) call event listener on node freeswitch@kazoo-test.voip.domain.com received graceful shutdown request
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_fs_channels:431(<0.1534.0>) removed 1 channel(s) with id 262c021a-63ac-1239-9999-0242ac110006 on freeswitch@kazoo-test.voip.domain.com
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:539(<0.8327.10>) checking interaction cache for 262c021a-63ac-1239-9999-0242ac110006
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:539(<0.8282.10>) checking interaction cache for 262c021a-63ac-1239-9999-0242ac110006
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:553(<0.8327.10>) interaction cache for 262c021a-63ac-1239-9999-0242ac110006 not found
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:628(<0.8327.10>) publishing call event channel_destroy
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:553(<0.8282.10>) interaction cache for 262c021a-63ac-1239-9999-0242ac110006 not found
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:477(<0.8282.10>) our channel has been destroyed, executing any post-hangup commands
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:252(<0.8327.10>) application ecallmgr checked out worker <0.477.0> from pool kz_amqp_pool
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:1188(<0.8282.10>) started post hangup keep alive timer for 2000ms
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_channel:245(<0.477.0>) published to callevt(direct 2K) exchange (routing key call.CHANNEL_DESTROY.262c021a-63ac-1239-9999-0242ac110006) via <0.664.0>
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:737(<0.477.0>) published message 1598603679674564 for <0.8327.10>
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:539(<0.8282.10>) checking interaction cache for 262c021a-63ac-1239-9999-0242ac110006
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:553(<0.8282.10>) interaction cache for 262c021a-63ac-1239-9999-0242ac110006 not found
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:477(<0.8282.10>) our channel has been destroyed, executing any post-hangup commands
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:1199(<0.8282.10>) reset post hangup keep alive timer
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:508(<0.8282.10>) received control queue unconditional advance, skipping wait for command completion of 'hangup'
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:529(<0.8282.10>) command 'hangup' is not valid after hangup, skipping
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:1199(<0.8282.10>) reset post hangup keep alive timer
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:508(<0.8282.10>) received control queue unconditional advance, skipping wait for command completion of 'hangup'
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:519(<0.8282.10>) no call commands remain queued, hibernating
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:508(<0.8282.10>) received control queue unconditional advance, skipping wait for command completion of 'undefined'
Aug 28 09:34:39 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:519(<0.8282.10>) no call commands remain queued, hibernating
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|webhooks_channel_util:32(<0.28170.86>) evt CHANNEL_DESTROY for 93813fae04349906f8341b6331aa295c
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|webhooks_util:226(<0.28170.86>) sending hook CHANNEL_DESTROY(0f9dcb1f5021989ad8ea59660c079fdf) with interaction id 88c4690c90 via 'post' (retries 3): http://127.0.0.1:8080/
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|kzs_publish:50(<0.28124.86>) maybe publishing db/doc change: false
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|kz_http:271(<0.28170.86>) 80.44ms: post http://127.0.0.1:8080/
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|webhooks_util:262(<0.28170.86>) sent hook call event CHANNEL_DESTROY(0f9dcb1f5021989ad8ea59660c079fdf) with interaction id 88c4690c90 successfully
Aug 28 09:34:39 kazoo-test 2600hz[578]: |262c021a-63ac-1239-9999-0242ac110006|kzs_publish:50(<0.28170.86>) maybe publishing db/doc change: false
Aug 28 09:34:40 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:252(<0.8325.10>) application ecallmgr checked out worker <0.490.0> from pool kz_amqp_pool
Aug 28 09:34:40 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_channel:245(<0.490.0>) published to presence(direct 655B) exchange (routing key dialog.carrier%2Ecom.262c021a-63ac-1239-9999-0242ac110006) via <0.699.0>
Aug 28 09:34:40 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|kz_amqp_worker:737(<0.490.0>) published message 39aac05015523331 for <0.8325.10>
Aug 28 09:34:41 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:291(<0.8282.10>) no new commands received after channel destruction, our job here is done
Aug 28 09:34:41 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_control:376(<0.8282.10>) control queue was up for 4234866 microseconds
Aug 28 09:34:44 kazoo-test 2600hz[577]: |262c021a-63ac-1239-9999-0242ac110006|ecallmgr_call_events:452(<0.8280.10>) goodbye and thanks for all the fish: normal

 

  • Administrators
mc_

mc_

Posted
  • Administrators
Posted

Everything about this log suggests it hung up.

Check the FreeSWITCH logs to see if it generated the SIP BYE?

simonp22

simonp22

Posted
  • Author
Posted

Hi @mc_

Looks like the SIP BYE is being generated in Freeswitch too... hmmm 

262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] switch_ivr.c:679 sofia/sipinterface_1/441111222333 @carrier.com skip receive message [AUDIO_SYNC] (channel is hungup already)
262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] switch_core_state_machine.c:848 (sofia/sipinterface_1/441111222333 @carrier.com) Callstate Change ACTIVE -> HANGUP
262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] switch_core_state_machine.c:850 (sofia/sipinterface_1/441111222333 @carrier.com) State HANGUP
262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] mod_sofia.c:453 Channel sofia/sipinterface_1/441111222333 @carrier.com hanging up, cause: NORMAL_CLEARING
262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] mod_sofia.c:507 Sending BYE to sofia/sipinterface_1/441111222333 @carrier.com
262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/441111222333 @carrier.com Standard HANGUP, cause: NORMAL_CLEARING
262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] switch_core_state_machine.c:850 (sofia/sipinterface_1/441111222333 @carrier.com) State HANGUP going to sleep
262c021a-63ac-1239-9999-0242ac110006 2020-08-28 09:34:39.674564 78.43% [DEBUG] switch_core_state_machine.c:620 (sofia/sipinterface_1/441111222333 @carrier.com) State Change CS_HANGUP -> CS_REPORTING

 

 Share
Go to topic listing
×
×
  • Create New...