play_and_detect_start_input_timers ................................2020-01-16 18:46:55.668214 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables 2020-01-16 18:46:55.668214 [NOTICE] switch_channel.c:1118 New Channel null/+15553334444 [d372bdd3-7116-4ade-92cc-526cf18a1c11] 2020-01-16 18:46:55.668214 [DEBUG] mod_loopback.c:1335 null/+15553334444 setup codec L16/8000/20 2020-01-16 18:46:55.668214 [NOTICE] switch_channel.c:1116 Rename Channel null/+15553334444->null/+15553334444 [d372bdd3-7116-4ade-92cc-526cf18a1c11] 2020-01-16 18:46:55.668214 [DEBUG] mod_loopback.c:1692 (null/+15553334444) State Change CS_NEW -> CS_INIT 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:585 (null/+15553334444) Running State Change CS_INIT (Cur 1 Tot 4) 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:628 (null/+15553334444) State INIT 2020-01-16 18:46:55.668214 [DEBUG] mod_loopback.c:1393 (null/+15553334444) State Change CS_INIT -> CS_ROUTING 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:628 (null/+15553334444) State INIT going to sleep 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:585 (null/+15553334444) Running State Change CS_ROUTING (Cur 1 Tot 4) 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:644 (null/+15553334444) State ROUTING 2020-01-16 18:46:55.668214 [DEBUG] switch_ivr_originate.c:67 (null/+15553334444) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:644 (null/+15553334444) State ROUTING going to sleep 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:585 (null/+15553334444) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 4) 2020-01-16 18:46:55.668214 [DEBUG] switch_core_state_machine.c:663 (null/+15553334444) State CONSUME_MEDIA 2020-01-16 18:46:55.668214 [DEBUG] mod_loopback.c:1460 CHANNEL CONSUME_MEDIA 2020-01-16 18:46:55.668214 [DEBUG] mod_loopback.c:1469 CHANNEL CONSUME_MEDIA - answering in 1 ms 2020-01-16 18:46:56.668481 [NOTICE] mod_loopback.c:1476 Channel [null/+15553334444] has been answered 2020-01-16 18:46:56.668481 [DEBUG] switch_channel.c:3865 (null/+15553334444) Callstate Change DOWN -> ACTIVE 2020-01-16 18:46:56.668481 [DEBUG] switch_core_state_machine.c:663 (null/+15553334444) State CONSUME_MEDIA going to sleep 2020-01-16 18:46:56.668481 [DEBUG] switch_ivr_originate.c:3809 Originate Resulted in Success: [null/+15553334444] 2020-01-16 18:46:56.668481 [DEBUG] test_asr.c:258 (null/+15553334444) State Change CS_CONSUME_MEDIA -> CS_SOFT_EXECUTE 2020-01-16 18:46:56.668481 [DEBUG] switch_core_state_machine.c:585 (null/+15553334444) Running State Change CS_SOFT_EXECUTE (Cur 1 Tot 4) 2020-01-16 18:46:56.668481 [DEBUG] switch_core_state_machine.c:657 (null/+15553334444) State SOFT_EXECUTE 2020-01-16 18:46:56.668481 [DEBUG] switch_core_state_machine.c:401 null/+15553334444 Standard SOFT_EXECUTE 2020-01-16 18:46:56.668481 [DEBUG] switch_core_state_machine.c:657 (null/+15553334444) State SOFT_EXECUTE going to sleep 2020-01-16 18:46:56.668481 [DEBUG] switch_ivr_async.c:1352 Record session sample rate: 8000 -> 8000 2020-01-16 18:46:56.668481 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to null/+15553334444 2020-01-16 18:46:56.668481 [DEBUG] switch_scheduler.c:252 Added task 5 switch_ivr_schedule_hangup (d372bdd3-7116-4ade-92cc-526cf18a1c11) to run at 1579200476 2020-01-16 18:46:56.668481 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to null/+15553334444 EXECUTE [depth=0] null/+15553334444 play_and_detect_speech(/freeswitch/src/mod/applications/mod_test/test/sounds/ivr-please_state_your_name_and_reason_for_calling.wav detect:test {start-input-timers=true,no-input-timeout=5000,speech-timeout=10000,channel-uuid=d372bdd3-7116-4ade-92cc-526cf18a1c11}default) 2020-01-16 18:46:56.668481 [INFO] mod_test.c:97 codec = L16, rate = 8000, dest = (null) 2020-01-16 18:46:56.668481 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to null/+15553334444 2020-01-16 18:46:56.668481 [DEBUG] mod_test.c:337 start-input-timers = 1 2020-01-16 18:46:56.668481 [DEBUG] mod_test.c:326 no-input-timeout = 5000 2020-01-16 18:46:56.668481 [DEBUG] mod_test.c:329 speech-timeout = 10000 2020-01-16 18:46:56.668481 [DEBUG] mod_test.c:352 channel-uuid = d372bdd3-7116-4ade-92cc-526cf18a1c11 2020-01-16 18:46:56.668481 [INFO] mod_test.c:134 load grammar default 2020-01-16 18:46:56.668481 [DEBUG] switch_ivr_play_say.c:1492 Codec Activated L16@8000hz 1 channels 20ms 2020-01-16 18:46:56.668481 [DEBUG] switch_core_io.c:448 Setting BUG Codec L16:100 2020-01-16 18:46:56.668481 [DEBUG] switch_ivr_async.c:1641 No silence detection configured; assuming start of speech 2020-01-16 18:46:59.048126 [DEBUG] switch_ivr_play_say.c:1933 done playing file /freeswitch/src/mod/applications/mod_test/test/sounds/ivr-please_state_your_name_and_reason_for_calling.wav 2020-01-16 18:46:59.048126 [DEBUG] mod_test.c:304 start_input_timers 2020-01-16 18:46:59.048126 [INFO] mod_test.c:310 Input timers already started 2020-01-16 18:46:59.048126 [INFO] switch_ivr_async.c:4600 (null/+15553334444) WAITING FOR RESULT 2020-01-16 18:46:59.048126 [DEBUG] switch_ivr.c:195 Codec Activated L16@8000hz 1 channels 20ms 2020-01-16 18:47:01.688165 [DEBUG] mod_test.c:241 NO INPUT TIMEOUT 5019ms 2020-01-16 18:47:01.688165 [DEBUG] mod_test.c:273 Result: NO INPUT 2020-01-16 18:47:01.708435 [INFO] switch_ivr_async.c:4501 (null/+15553334444) DETECTED SPEECH 2020-01-16 18:47:01.708435 [NOTICE] test_asr.c:279 Hangup null/+15553334444 [CS_SOFT_EXECUTE] [NORMAL_CLEARING] 2020-01-16 18:47:01.708435 [DEBUG] mod_loopback.c:1439 CHANNEL SWITCH_SIG_KILL - hanging up 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:585 (null/+15553334444) Running State Change CS_HANGUP (Cur 1 Tot 4) 2020-01-16 18:47:01.708435 [DEBUG] switch_core_media_bug.c:1295 Removing BUG from null/+15553334444 2020-01-16 18:47:01.708435 [DEBUG] switch_ivr_async.c:1446 Stop recording file /tmp/play_and_detect_start_input_timers.wav 2020-01-16 18:47:01.708435 [DEBUG] switch_ivr_async.c:1521 Channel is hung up 2020-01-16 18:47:01.708435 [DEBUG] switch_core_media_bug.c:1295 Removing BUG from null/+15553334444 2020-01-16 18:47:01.708435 [NOTICE] mod_test.c:154 ASR closing ... 2020-01-16 18:47:01.708435 [DEBUG] switch_core_media_bug.c:1295 Removing BUG from null/+15553334444 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:848 (null/+15553334444) Callstate Change ACTIVE -> HANGUP 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:850 (null/+15553334444) State HANGUP 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:60 null/+15553334444 Standard HANGUP, cause: NORMAL_CLEARING 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:850 (null/+15553334444) State HANGUP going to sleep 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:620 (null/+15553334444) State Change CS_HANGUP -> CS_REPORTING 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:585 (null/+15553334444) Running State Change CS_REPORTING (Cur 1 Tot 4) 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:936 (null/+15553334444) State REPORTING 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:174 null/+15553334444 Standard REPORTING, cause: NORMAL_CLEARING 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:936 (null/+15553334444) State REPORTING going to sleep 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:611 (null/+15553334444) State Change CS_REPORTING -> CS_DESTROY 2020-01-16 18:47:01.708435 [DEBUG] switch_core_session.c:1726 Session 4 (null/+15553334444) Locked, Waiting on external entities 2020-01-16 18:47:01.708435 [NOTICE] switch_core_session.c:1744 Session 4 (null/+15553334444) Ended 2020-01-16 18:47:01.708435 [NOTICE] switch_core_session.c:1748 Close Channel null/+15553334444 [CS_DESTROY] 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:739 (null/+15553334444) Running State Change CS_DESTROY (Cur 0 Tot 4) 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:749 (null/+15553334444) State DESTROY 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:181 null/+15553334444 Standard DESTROY 2020-01-16 18:47:01.708435 [DEBUG] switch_core_state_machine.c:749 (null/+15553334444) State DESTROY going to sleep 2020-01-16 18:47:02.188142 [DEBUG] switch_scheduler.c:147 Deleting task 5 switch_ivr_schedule_hangup (d372bdd3-7116-4ade-92cc-526cf18a1c11) FAIL *** u