From Soft Guinea Pig, 7 Years ago, written in Plain Text.
- view diff
Embed
  1. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:40 sofia/external/XXXXXXXXXX Standard INIT
  2. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:48 (sofia/external/XXXXXXXXXX) State Change CS_INIT -> CS_ROUTING
  3. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:516 (sofia/external/XXXXXXXXXX) State INIT going to sleep
  4. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:473 (sofia/external/XXXXXXXXXX) Running State Change CS_ROUTING
  5. 2017-06-20 22:42:53.947939 [DEBUG] sofia.c:6760 Channel sofia/external/XXXXXXXXXX entering state [calling][0]
  6. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:532 (sofia/external/XXXXXXXXXX) State ROUTING
  7. 2017-06-20 22:42:53.947939 [DEBUG] mod_sofia.c:141 sofia/external/XXXXXXXXXX SOFIA ROUTING
  8. 2017-06-20 22:42:53.947939 [DEBUG] switch_ivr_originate.c:67 (sofia/external/XXXXXXXXXX) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  9. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:532 (sofia/external/XXXXXXXXXX) State ROUTING going to sleep
  10. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:473 (sofia/external/XXXXXXXXXX) Running State Change CS_CONSUME_MEDIA
  11. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:551 (sofia/external/XXXXXXXXXX) State CONSUME_MEDIA
  12. 2017-06-20 22:42:53.947939 [DEBUG] switch_core_state_machine.c:551 (sofia/external/XXXXXXXXXX) State CONSUME_MEDIA going to sleep
  13. 2017-06-20 22:42:54.087940 [DEBUG] sofia.c:6760 Channel sofia/external/XXXXXXXXXX entering state [terminated][403]
  14. 2017-06-20 22:42:54.087940 [NOTICE] sofia.c:7779 Hangup sofia/external/XXXXXXXXXX [CS_CONSUME_MEDIA] [CALL_REJECTED]
  15. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:473 (sofia/external/XXXXXXXXXX) Running State Change CS_HANGUP
  16. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:739 (sofia/external/XXXXXXXXXX) Callstate Change DOWN -> HANGUP
  17. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:741 (sofia/external/XXXXXXXXXX) State HANGUP
  18. 2017-06-20 22:42:54.087940 [DEBUG] mod_sofia.c:431 Channel sofia/external/XXXXXXXXXX hanging up, cause: CALL_REJECTED
  19. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:60 sofia/external/XXXXXXXXXX Standard HANGUP, cause: CALL_REJECTED
  20. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:741 (sofia/external/XXXXXXXXXX) State HANGUP going to sleep
  21. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:508 (sofia/external/XXXXXXXXXX) State Change CS_HANGUP -> CS_REPORTING
  22. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:473 (sofia/external/XXXXXXXXXX) Running State Change CS_REPORTING
  23. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:827 (sofia/external/XXXXXXXXXX) State REPORTING
  24. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:104 sofia/external/XXXXXXXXXX Standard REPORTING, cause: CALL_REJECTED
  25. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:827 (sofia/external/XXXXXXXXXX) State REPORTING going to sleep
  26. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_state_machine.c:499 (sofia/external/XXXXXXXXXX) State Change CS_REPORTING -> CS_DESTROY
  27. 2017-06-20 22:42:54.087940 [DEBUG] switch_core_session.c:1646 Session 14 (sofia/external/XXXXXXXXXX) Locked, Waiting on external entities
  28. 2017-06-20 22:42:54.107935 [DEBUG] switch_ivr_originate.c:3751 Originate Resulted in Error Cause: 21 [CALL_REJECTED]
  29. 2017-06-20 22:42:54.107935 [NOTICE] switch_core_session.c:1664 Session 14 (sofia/external/XXXXXXXXXX) Ended
  30. 2017-06-20 22:42:54.107935 [NOTICE] switch_core_session.c:1668 Close Channel sofia/external/XXXXXXXXXX [CS_DESTROY]
  31. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:630 (sofia/external/XXXXXXXXXX) Running State Change CS_DESTROY
  32. 2017-06-20 22:42:54.107935 [INFO] mod_dptools.c:3379 Originate Failed.  Cause: CALL_REJECTED
  33. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:640 (sofia/external/XXXXXXXXXX) State DESTROY
  34. 2017-06-20 22:42:54.107935 [DEBUG] mod_sofia.c:341 sofia/external/XXXXXXXXXX SOFIA DESTROY
  35. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:111 sofia/external/XXXXXXXXXX Standard DESTROY
  36. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:640 (sofia/external/XXXXXXXXXX) State DESTROY going to sleep
  37. EXECUTE sofia/external/12146846400@999.999.999.2 bridge(sofia/gateway/3c820e49-450b-4626-8bbe-561188fc09f2/XXXXXXXXXX)
  38. 2017-06-20 22:42:54.107935 [DEBUG] switch_channel.c:1247 sofia/external/12146846400@999.999.999.2 EXPORTING[export_vars] [origination_callee_id_name]=[XXXXXXXXXX] to event
  39. 2017-06-20 22:42:54.107935 [DEBUG] switch_channel.c:1247 sofia/external/12146846400@999.999.999.2 EXPORTING[export_vars] [dialed_extension]=[1502] to event
  40. 2017-06-20 22:42:54.107935 [DEBUG] switch_channel.c:1247 sofia/external/12146846400@999.999.999.2 EXPORTING[export_vars] [origination_callee_id_name]=[XXXXXXXXXX] to event
  41. 2017-06-20 22:42:54.107935 [DEBUG] switch_channel.c:1247 sofia/external/12146846400@999.999.999.2 EXPORTING[export_vars] [origination_callee_id_name]=[XXXXXXXXXX] to event
  42. 2017-06-20 22:42:54.107935 [DEBUG] switch_ivr_originate.c:2128 Parsing global variables
  43. 2017-06-20 22:42:54.107935 [NOTICE] switch_channel.c:1101 New Channel sofia/external/XXXXXXXXXX [b52f5008-5633-11e7-8041-4d076d508355]
  44. 2017-06-20 22:42:54.107935 [DEBUG] mod_sofia.c:4776 (sofia/external/XXXXXXXXXX) State Change CS_NEW -> CS_INIT
  45. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:473 (sofia/external/XXXXXXXXXX) Running State Change CS_INIT
  46. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:516 (sofia/external/XXXXXXXXXX) State INIT
  47. 2017-06-20 22:42:54.107935 [DEBUG] mod_sofia.c:88 sofia/external/XXXXXXXXXX SOFIA INIT
  48. 2017-06-20 22:42:54.107935 [DEBUG] sofia_glue.c:1257 sofia/external/XXXXXXXXXX sending invite version: 1.6.6  64bit
  49. Local SDP:
  50. v=0
  51. o=FreeSWITCH 1497991928 1497991929 IN IP4 999.999.999.3
  52. s=FreeSWITCH
  53. c=IN IP4 999.999.999.3
  54. t=0 0
  55. m=audio 24646 RTP/AVP 0 101 13
  56. a=rtpmap:0 PCMU/8000
  57. a=rtpmap:101 telephone-event/8000
  58. a=fmtp:101 0-16
  59. a=rtpmap:13 CN/8000
  60. a=ptime:20
  61. a=sendrecv
  62.  
  63. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:40 sofia/external/XXXXXXXXXX Standard INIT
  64. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:48 (sofia/external/XXXXXXXXXX) State Change CS_INIT -> CS_ROUTING
  65. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:516 (sofia/external/XXXXXXXXXX) State INIT going to sleep
  66. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:473 (sofia/external/XXXXXXXXXX) Running State Change CS_ROUTING
  67. 2017-06-20 22:42:54.107935 [DEBUG] sofia.c:6760 Channel sofia/external/XXXXXXXXXX entering state [calling][0]
  68. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:532 (sofia/external/XXXXXXXXXX) State ROUTING
  69. 2017-06-20 22:42:54.107935 [DEBUG] mod_sofia.c:141 sofia/external/XXXXXXXXXX SOFIA ROUTING
  70. 2017-06-20 22:42:54.107935 [DEBUG] switch_ivr_originate.c:67 (sofia/external/XXXXXXXXXX) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  71. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:532 (sofia/external/XXXXXXXXXX) State ROUTING going to sleep
  72. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:473 (sofia/external/XXXXXXXXXX) Running State Change CS_CONSUME_MEDIA
  73. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:551 (sofia/external/XXXXXXXXXX) State CONSUME_MEDIA
  74. 2017-06-20 22:42:54.107935 [DEBUG] switch_core_state_machine.c:551 (sofia/external/XXXXXXXXXX) State CONSUME_MEDIA going to sleep
  75.  
  76. HERE'S THE DELAY
  77.  
  78.  
  79. 2017-06-20 22:42:57.547949 [DEBUG] sofia.c:6760 Channel sofia/external/XXXXXXXXXX entering state [proceeding][183]
  80. 2017-06-20 22:42:57.547949 [DEBUG] sofia.c:6770 Remote SDP:
  81. v=0
  82. o=FreeSWITCH 2838459558 2838459560 IN IP4 162.212.218.151
  83. s=FreeSWITCH
  84. c=IN IP4 162.212.218.151
  85. t=0 0
  86. m=audio 49540 RTP/AVP 0 101
  87. a=rtpmap:0 PCMU/8000
  88. a=rtpmap:101 telephone-event/8000
  89. a=fmtp:101 0-15
  90. a=maxptime:20
  91.  
  92. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  93. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:4216 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  94. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:4077 Set telephone-event payload to 101@8000
  95. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:2906 Set Codec sofia/external/XXXXXXXXXX PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  96. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_codec.c:111 sofia/external/XXXXXXXXXX Original read codec set to PCMU:0
  97. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:4429 Set telephone-event payload to 101@8000
  98. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:4485 sofia/external/XXXXXXXXXX Set 2833 dtmf send payload to 101 recv payload to 101
  99. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:6033 AUDIO RTP [sofia/external/XXXXXXXXXX] 999.999.999.3 port 24646 -> 162.212.218.151 port 49540 codec: 0 ms: 20
  100. 2017-06-20 22:42:57.547949 [DEBUG] switch_rtp.c:3802 Starting timer [soft] 160 bytes per 20ms
  101. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:6332 sofia/external/XXXXXXXXXX Set 2833 dtmf send payload to 101
  102. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:6339 sofia/external/XXXXXXXXXX Set 2833 dtmf receive payload to 101
  103. 2017-06-20 22:42:57.547949 [DEBUG] switch_core_media.c:6362 sofia/external/XXXXXXXXXX Set rtp dtmf delay to 40
  104. 2017-06-20 22:42:57.547949 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/XXXXXXXXXX!
  105.