Jump to content
2600Hz Community

Callflow not executing hangup


simonp22
 Share

Recommended Posts

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

 

Link to comment
Share on other sites

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

 

Link to comment
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.

Guest
Reply to this topic...

×   Pasted as rich text.   Paste as plain text instead

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

Loading...
 Share

×
×
  • Create New...