Hello,<br><br>we had some trouble while executing a bulk call process with originating a parallel call of 200. Because in many cases, FreeSWITCH has notified hangups (SWITCH_EVENT_CHANNEL_HANGUP_COMPLETE) with the wrong hangup-cause. Instead of notifying the successful state, we got the NO_ANSWER hangup cause. BUSY and NO_ANSWER states are candidates for retries, therefor many numbers are called/payed twice. See log below.<br>
<br>Some other questions:<br><br>B) Is the originate_timeout value an overall timer or a timer for the ringing (starts if SIP code 180 incomes?) stage.<br><br>C) We are originating each number in a separate thread and listen to the channel events for updating the call result. Should we change this implementation or is this a good scenario/standard way. Related to the call result, if it is busy or not answered, the call is retried after 30 min. What are the recommends on this side to be ensured, the correct hangup case be got and the number is not called twice..<br>
<br>D) What do I have to bear in mind for bulk calls with parallel calls over 200.<br><br>Thanks for your answer in advance.<br><br>Ali<br><br><br>An extraction of the log (regard to the first issue):<br><br>2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable string 0 = [sip_from_uri=sip:xxxx@xxxxx]<br>
2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable string 1 = [ignore_early_media=true]<br>2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable string 2 = [sip_cid_type=none]<br>2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable string 3 = [originate_timeout=40] <br>
2010-08-17 22:41:09.904378 [NOTICE] switch_channel.c:779 New Channel sofia/internal/9055599XXXXX [9e4b396e-3d99-445f-a2e8-227e99f3f0ef] <br>2010-08-17 22:41:12.641362 [DEBUG] mod_sofia.c:3892 (sofia/internal/9055599XXXXX) State Change CS_NEW -> CS_INIT<br>
2010-08-17 22:41:12.641362 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/9055599XXXXX [BREAK]<br>2010-08-17 22:41:12.641362 [DEBUG] switch_core_session.c:454 sofia/internal/9055599XXXXX set UUID=9dc8a739-f439-4815-981a-347b7a90a1a8<br>
2010-08-17 22:41:12.642441 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/9055599XXXXX) Running State Change CS_INIT<br>2010-08-17 22:41:12.642441 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/9055599XXXXX) State INIT<br>
2010-08-17 22:41:12.642441 [DEBUG] mod_sofia.c:83 sofia/internal/9055599XXXXX SOFIA INIT<br>2010-08-17 22:41:12.643399 [DEBUG] mod_sofia.c:119 (sofia/internal/9055599XXXXX) State Change CS_INIT -> CS_ROUTING<br>2010-08-17 22:41:12.643399 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/9055599XXXXX [BREAK]<br>
2010-08-17 22:41:12.643399 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/9055599XXXXX) State INIT going to sleep<br>2010-08-17 22:41:12.643399 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/9055599XXXXX) Running State Change CS_ROUTING<br>
2010-08-17 22:41:12.644456 [DEBUG] switch_channel.c:1512 (sofia/internal/9055599XXXXX) Callstate Change DOWN -> RINGING<br>2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/9055599XXXXX) State ROUTING<br>
2010-08-17 22:41:12.644456 [DEBUG] mod_sofia.c:142 sofia/internal/9055599XXXXX SOFIA ROUTING<br>2010-08-17 22:41:12.644456 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/9055599XXXXX) State Change CS_ROUTING -> CS_CONSUME_MEDIA<br>
2010-08-17 22:41:12.644456 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/9055599XXXXX [BREAK]<br>2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/9055599XXXXX) State ROUTING going to sleep<br>
2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/9055599XXXXX) Running State Change CS_CONSUME_MEDIA<br>2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/9055599XXXXX) State CONSUME_MEDIA<br>
2010-08-17 22:41:12.645373 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/9055599XXXXX) State CONSUME_MEDIA going to sleep <br>2010-08-17 22:41:42.806367 [DEBUG] sofia.c:4318 Channel sofia/internal/9055599XXXXX entering state [calling][0] <br>
2010-08-17 22:41:42.890442 [INFO] sofia.c:662 sofia/internal/9055599XXXXX Update Callee ID to "9055599XXXXX" <9055599XXXXX><br>2010-08-17 22:41:42.894355 [DEBUG] sofia.c:4318 Channel sofia/internal/9055599XXXXX entering state [proceeding][183]<br>
2010-08-17 22:41:42.894355 [NOTICE] sofia.c:4390 Ring-Ready sofia/internal/9055599XXXXX!<br><span style="background-color: rgb(255, 255, 51);">2010-08-17 22:41:42.895440 [DEBUG] sofia.c:4318 Channel sofia/internal/9055599XXXXX entering state [proceeding][183]</span><br>
2010-08-17 22:41:42.895440 [DEBUG] sofia.c:4329 Remote SDP: <br>2010-08-17 22:41:42.895440 [DEBUG] sofia_glue.c:2444 Set Codec sofia/internal/9055599XXXXX PCMA/8000 20 ms 160 samples<br>2010-08-17 22:41:42.896357 [DEBUG] sofia_glue.c:3937 Set 2833 dtmf send payload to 101<br>
2010-08-17 22:41:42.896357 [DEBUG] sofia_glue.c:2684 AUDIO RTP [sofia/internal/9055599XXXXX] 10.100.224.10 port 31416 -> 10.100.199.19 port 18620 codec: 8 ms: 20<br>2010-08-17 22:41:42.896357 [DEBUG] switch_rtp.c:1413 Starting timer [soft] 160 bytes per 20ms<br>
2010-08-17 22:41:42.897431 [DEBUG] sofia_glue.c:2894 Set 2833 dtmf send payload to 101<br>2010-08-17 22:41:42.897431 [DEBUG] sofia_glue.c:2899 Set 2833 dtmf receive payload to 101<br>2010-08-17 22:41:42.897431 [NOTICE] sofia_glue.c:3292 Pre-Answer sofia/internal/9055599XXXXX!<br>
2010-08-17 22:41:42.897431 [DEBUG] switch_channel.c:2397 (sofia/internal/9055599XXXXX) Callstate Change RINGING -> EARLY<br><span style="background-color: rgb(255, 255, 102);"> 2010-08-17 22:41:42.916461 [DEBUG] sofia.c:4313 Channel sofia/internal/9055599XXXXX skipping state [proceeding][180] </span><br>
<span style="background-color: rgb(255, 255, 51);">2010-08-17 22:41:43.434412 [DEBUG] sofia.c:4318 Channel sofia/internal/9055599XXXXX entering state [completing][200]</span><br>2010-08-17 22:41:43.434412 [DEBUG] sofia.c:4326 Duplicate SDP <br>
2010-08-17 22:41:52.000488 [DEBUG] switch_channel.c:2309 (sofia/internal/9055599XXXXX) Callstate Change EARLY -> HANGUP <br>2010-08-17 22:41:52.000488 [NOTICE] switch_ivr_originate.c:3282 Hangup sofia/internal/9055599XXXXX [CS_CONSUME_MEDIA] [NO_ANSWER]<br>
2010-08-17 22:41:52.000488 [DEBUG] switch_channel.c:2325 Send signal sofia/internal/9055599XXXXX [KILL]<br>2010-08-17 22:41:52.000488 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/9055599XXXXX) Running State Change CS_HANGUP<br>
2010-08-17 22:41:52.000488 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/9055599XXXXX) State HANGUP<br><span style="background-color: rgb(255, 255, 51);">2010-08-17 22:41:52.000488 [DEBUG] mod_sofia.c:453 Channel sofia/internal/9055599XXXXX hanging up, cause: NO_ANSWER</span><br>
2010-08-17 22:41:52.000488 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/9055599XXXXX [BREAK] <br>2010-08-17 22:41:55.204396 [DEBUG] mod_sofia.c:506 Sending CANCEL to sofia/internal/9055599XXXXX<br>2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:46 sofia/internal/9055599XXXXX Standard HANGUP, cause: NO_ANSWER<br>
2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/9055599XXXXX) State HANGUP going to sleep<br>2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/9055599XXXXX) State Change CS_HANGUP -> CS_REPORTING<br>
2010-08-17 22:41:55.204396 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/9055599XXXXX [BREAK]<br>2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/9055599XXXXX) Running State Change CS_REPORTING<br>
2010-08-17 22:41:55.205401 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/9055599XXXXX) State REPORTING<br>2010-08-17 22:41:55.205401 [DEBUG] switch_core_state_machine.c:53 sofia/internal/9055599XXXXX Standard REPORTING, cause: NO_ANSWER<br>
2010-08-17 22:41:55.205401 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/9055599XXXXX) State REPORTING going to sleep<br>2010-08-17 22:41:55.206428 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/9055599XXXXX) State Change CS_REPORTING -> CS_DESTROY<br>
2010-08-17 22:41:55.206428 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/9055599XXXXX [BREAK]<br>2010-08-17 22:41:55.206428 [DEBUG] switch_core_session.c:1202 Session 18770 (sofia/internal/9055599XXXXX) Locked, Waiting on external entities<br>
2010-08-17 22:41:55.206428 [NOTICE] switch_core_session.c:1220 Session 18770 (sofia/internal/9055599XXXXX) Ended<br>2010-08-17 22:41:55.206428 [NOTICE] switch_core_session.c:1222 Close Channel sofia/internal/9055599XXXXX [CS_DESTROY]<br>
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:427 (sofia/internal/9055599XXXXX) Callstate Change HANGUP -> DOWN<br>2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/9055599XXXXX) Running State Change CS_DESTROY<br>
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/9055599XXXXX) State DESTROY<br>2010-08-17 22:41:55.207463 [DEBUG] mod_sofia.c:358 sofia/internal/9055599XXXXX SOFIA DESTROY<br>2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:60 sofia/internal/9055599XXXXX Standard DESTROY<br>
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/9055599XXXXX) State DESTROY going to sleep <br><br><br>