FreeSWITCH Pastebin

Untitled

From Crimson Tamarin, 1 Year ago, written in Plain Text.
- view diff
URL https://pastebin.freeswitch.org/view/bee4c249
Embed
Download Paste or View Raw
  1. +OK log level  [7]
  2. 2023-02-23 16:59:48.733445 99.47% [NOTICE] switch_channel.c:1123 New Channel sofia/external/7182087657@sip.telnyx.com [94a98667-27f0-44a9-840f-1eb9a8ba7a9e]
  3. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7182087657@sip.telnyx.com) Running State Change CS_NEW (Cur 1 Tot 6679)
  4. 2023-02-23 16:59:48.733445 99.47% [INFO] sofia.c:10468 sofia/external/7182087657@sip.telnyx.com receiving invite from 144.202.23.145:5060 version: 1.10.8 -release.14 64bit call-id: f5e56634-a0f9-4133-bae0-20aaaf996f63
  5. 2023-02-23 16:59:48.733445 99.47% [DEBUG] sofia.c:7502 Channel sofia/external/7182087657@sip.telnyx.com entering state [received][100]
  6. 2023-02-23 16:59:48.733445 99.47% [DEBUG] sofia.c:7512 Remote SDP:
  7. v=0
  8. o=Telnyx 1677152944 1677152945 IN IP4 64.16.227.16
  9. s=Telnyx
  10. c=IN IP4 64.16.227.16
  11. t=0 0
  12. m=audio 18644 RTP/AVP 9 0 8 18 101
  13. a=rtpmap:9 G722/8000
  14. a=rtpmap:0 PCMU/8000
  15. a=rtpmap:8 PCMA/8000
  16. a=rtpmap:18 G729/8000
  17. a=fmtp:18 annexb=no
  18. a=rtpmap:101 telephone-event/8000
  19. a=fmtp:101 0-15
  20. a=rtcp:18645 IN IP4 64.16.227.16
  21. a=ptime:20
  22.  
  23. 2023-02-23 16:59:48.733445 99.47% [DEBUG] sofia.c:7915 (sofia/external/7182087657@sip.telnyx.com) State Change CS_NEW -> CS_INIT
  24. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:600 (sofia/external/7182087657@sip.telnyx.com) State NEW
  25. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7182087657@sip.telnyx.com) Running State Change CS_INIT (Cur 1 Tot 6679)
  26. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:624 (sofia/external/7182087657@sip.telnyx.com) State INIT
  27. 2023-02-23 16:59:48.733445 99.47% [DEBUG] mod_sofia.c:97 sofia/external/7182087657@sip.telnyx.com SOFIA INIT
  28. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:40 sofia/external/7182087657@sip.telnyx.com Standard INIT
  29. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:48 (sofia/external/7182087657@sip.telnyx.com) State Change CS_INIT -> CS_ROUTING
  30. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:624 (sofia/external/7182087657@sip.telnyx.com) State INIT going to sleep
  31. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7182087657@sip.telnyx.com) Running State Change CS_ROUTING (Cur 1 Tot 6679)
  32. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_channel.c:2380 (sofia/external/7182087657@sip.telnyx.com) Callstate Change DOWN -> RINGING
  33. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:640 (sofia/external/7182087657@sip.telnyx.com) State ROUTING
  34. 2023-02-23 16:59:48.733445 99.47% [DEBUG] mod_sofia.c:158 sofia/external/7182087657@sip.telnyx.com SOFIA ROUTING
  35. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:230 sofia/external/7182087657@sip.telnyx.com Standard ROUTING
  36. 2023-02-23 16:59:48.733445 99.47% [INFO] mod_dialplan_xml.c:639 Processing VILLAGOMEZ,JOSH <7182087657>->7047417204 in context public
  37. Dialplan: sofia/external/7182087657@sip.telnyx.com parsing [public->public_conference_extensions] continue=false
  38. Dialplan: sofia/external/7182087657@sip.telnyx.com Regex (PASS) [public_conference_extensions] destination_number(7047417204) =~ /^(.*)$/ break=on-false
  39. Dialplan: sofia/external/7182087657@sip.telnyx.com Action python(routing_inbound)
  40. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:281 (sofia/external/7182087657@sip.telnyx.com) State Change CS_ROUTING -> CS_EXECUTE
  41. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:640 (sofia/external/7182087657@sip.telnyx.com) State ROUTING going to sleep
  42. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7182087657@sip.telnyx.com) Running State Change CS_EXECUTE (Cur 1 Tot 6679)
  43. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:647 (sofia/external/7182087657@sip.telnyx.com) State EXECUTE
  44. 2023-02-23 16:59:48.733445 99.47% [DEBUG] mod_sofia.c:213 sofia/external/7182087657@sip.telnyx.com SOFIA EXECUTE
  45. 2023-02-23 16:59:48.733445 99.47% [DEBUG] switch_core_state_machine.c:323 sofia/external/7182087657@sip.telnyx.com Standard EXECUTE
  46. EXECUTE [depth=0] sofia/external/7182087657@sip.telnyx.com python(routing_inbound)
  47. 2023-02-23 16:59:48.733445 99.47% [NOTICE] mod_python.c:213 Invoking py module: routing_inbound
  48. 2023-02-23 16:59:48.733445 99.47% [DEBUG] mod_python.c:306 Call python script
  49. 2023-02-23 16:59:48.733445 99.47% [INFO] switch_cpp.cpp:1392 Python INBOUND CALL !!
  50.  
  51. 2023-02-23 16:59:48.774592 99.47% [INFO] switch_cpp.cpp:1392 exten :1106 , domain :  inextrixdevs
  52. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable('hangup_after_bridge', 'true')
  53. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable('inherit_codec', 'true')
  54. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable('sip_h_X-Tenant', 'inextrixdevs')
  55. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable('continue_on_fail', 'true')
  56. EXECUTE [depth=0] sofia/external/7182087657@sip.telnyx.com set(ringback=%(2000,4000,440.0,480.0))
  57. 2023-02-23 16:59:48.774592 99.47% [DEBUG] mod_dptools.c:1673 SET sofia/external/7182087657@sip.telnyx.com [ringback]=[%(2000,4000,440.0,480.0)]
  58. 2023-02-23 16:59:48.774592 99.47% [INFO] switch_cpp.cpp:1392 Launch Auto Attendence
  59. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  60. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5718 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  61. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  62. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  63. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  64. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  65. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5718 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  66. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  67. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  68. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  69. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  70. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5718 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  71. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  72. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  73. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5663 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  74. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5579 Set telephone-event payload to 101@8000
  75. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:3883 Set Codec sofia/external/7182087657@sip.telnyx.com G722/8000 20 ms 160 samples 64000 bits 1 channels
  76. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_codec.c:111 sofia/external/7182087657@sip.telnyx.com Original read codec set to G722:9
  77. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5928 Set telephone-event payload to 101@8000
  78. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:5986 sofia/external/7182087657@sip.telnyx.com Set 2833 dtmf send payload to 101 recv payload to 101
  79. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:8787 AUDIO RTP [sofia/external/7182087657@sip.telnyx.com] 155.138.235.49 port 32502 -> 64.16.227.16 port 18644 codec: 9 ms: 20
  80. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
  81. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:9007 Activating RTCP PORT 18645
  82. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_rtp.c:5017 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 18645
  83. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_rtp.c:2776 Setting RTCP remote addr to 64.16.227.16:18645 2
  84. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:9099 sofia/external/7182087657@sip.telnyx.com Set 2833 dtmf send payload to 101
  85. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:9106 sofia/external/7182087657@sip.telnyx.com Set 2833 dtmf receive payload to 101
  86. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:9129 sofia/external/7182087657@sip.telnyx.com Set rtp dtmf delay to 40
  87. 2023-02-23 16:59:48.774592 99.47% [NOTICE] sofia_media.c:90 Pre-Answer sofia/external/7182087657@sip.telnyx.com!
  88. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_channel.c:3622 (sofia/external/7182087657@sip.telnyx.com) Callstate Change RINGING -> EARLY
  89. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_core_media.c:8769 Audio params are unchanged for sofia/external/7182087657@sip.telnyx.com.
  90. 2023-02-23 16:59:48.774592 99.47% [DEBUG] mod_sofia.c:913 Local SDP sofia/external/7182087657@sip.telnyx.com:
  91. v=0
  92. o=FreeSWITCH 1677139086 1677139087 IN IP4 155.138.235.49
  93. s=FreeSWITCH
  94. c=IN IP4 155.138.235.49
  95. t=0 0
  96. m=audio 32502 RTP/AVP 9 101
  97. a=rtpmap:9 G722/8000
  98. a=rtpmap:101 telephone-event/8000
  99. a=fmtp:101 0-15
  100. a=ptime:20
  101. a=sendrecv
  102. a=rtcp:32503 IN IP4 155.138.235.49
  103.  
  104. 2023-02-23 16:59:48.774592 99.47% [NOTICE] switch_cpp.cpp:703 Channel [sofia/external/7182087657@sip.telnyx.com] has been answered
  105. 2023-02-23 16:59:48.774592 99.47% [DEBUG] switch_channel.c:3950 (sofia/external/7182087657@sip.telnyx.com) Callstate Change EARLY -> ACTIVE
  106. 2023-02-23 16:59:48.774592 99.47% [INFO] switch_cpp.cpp:1392 Time Date   : 2023-02-23 10:59:48.810273-06:00
  107. 2023-02-23 16:59:48.774592 99.47% [INFO] switch_cpp.cpp:1392 Sound File 1  found
  108. 2023-02-23 16:59:48.774592 99.47% [DEBUG] sofia.c:7502 Channel sofia/external/7182087657@sip.telnyx.com entering state [completed][200]
  109. 2023-02-23 16:59:48.893445 99.47% [DEBUG] sofia.c:7502 Channel sofia/external/7182087657@sip.telnyx.com entering state [ready][200]
  110. 2023-02-23 16:59:49.053453 99.30% [DEBUG] switch_rtp.c:1982 rtcp_stats_init: audio ssrc[1750339364] base_seq[43863]
  111. 2023-02-23 16:59:49.053453 99.30% [DEBUG] switch_rtp.c:7925 Correct audio ip/port confirmed.
  112. 2023-02-23 16:59:50.293446 99.27% [DEBUG] switch_core_file.c:444 File /var/nfs_share/sounds/message-1106-inextrixdevs-1.wav sample rate 8000 doesn't match requested rate 16000
  113. 2023-02-23 16:59:50.293446 99.27% [DEBUG] switch_ivr_play_say.c:1566 Codec Activated L16@16000hz 1 channels 20ms
  114. 2023-02-23 16:59:52.893452 99.03% [DEBUG] switch_rtp.c:7326 Correct audio RTCP ip/port confirmed.
  115. 2023-02-23 16:59:58.073449 98.67% [DEBUG] switch_rtp.c:8170 RTP RECV DTMF 8:1120
  116. 2023-02-23 16:59:58.073449 98.67% [INFO] switch_channel.c:527 RECV DTMF 8:1120
  117. 2023-02-23 16:59:58.073449 98.67% [DEBUG] switch_ivr_play_say.c:2015 done playing file /var/nfs_share/sounds/message-1106-inextrixdevs-1.wav
  118. 2023-02-23 17:00:05.073451 98.53% [INFO] switch_cpp.cpp:1392  Intro exten : 8
  119. 2023-02-23 17:00:05.073451 98.53% [INFO] switch_cpp.cpp:1392 Accepted--
  120. 2023-02-23 17:00:05.073451 98.53% [INFO] switch_cpp.cpp:1392 Problem with index  '8'
  121. 2023-02-23 17:00:05.573462 98.53% [DEBUG] switch_core_file.c:444 File /var/nfs_share/sounds/that-was-an-invalid-entry.wav sample rate 48000 doesn't match requested rate 16000
  122. 2023-02-23 17:00:05.573462 98.53% [DEBUG] switch_ivr_play_say.c:1566 Codec Activated L16@16000hz 1 channels 20ms
  123. 2023-02-23 17:00:09.173458 98.20% [DEBUG] switch_ivr_play_say.c:2015 done playing file /var/nfs_share/sounds/that-was-an-invalid-entry.wav
  124. 2023-02-23 17:00:09.673479 98.20% [DEBUG] mod_python.c:308 Finished calling python script
  125. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_cpp.cpp:1209 sofia/external/7182087657@sip.telnyx.com destroy/unlink session from object
  126. 2023-02-23 17:00:09.673479 98.20% [NOTICE] switch_core_state_machine.c:382 sofia/external/7182087657@sip.telnyx.com has executed the last dialplan instruction, hanging up.
  127. 2023-02-23 17:00:09.673479 98.20% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/external/7182087657@sip.telnyx.com [CS_EXECUTE] [NORMAL_CLEARING]
  128. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:647 (sofia/external/7182087657@sip.telnyx.com) State EXECUTE going to sleep
  129. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7182087657@sip.telnyx.com) Running State Change CS_HANGUP (Cur 1 Tot 6679)
  130. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:844 (sofia/external/7182087657@sip.telnyx.com) Callstate Change ACTIVE -> HANGUP
  131. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:846 (sofia/external/7182087657@sip.telnyx.com) State HANGUP
  132. 2023-02-23 17:00:09.673479 98.20% [DEBUG] mod_sofia.c:468 Channel sofia/external/7182087657@sip.telnyx.com hanging up, cause: NORMAL_CLEARING
  133. 2023-02-23 17:00:09.673479 98.20% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/external/7182087657@sip.telnyx.com
  134. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:59 sofia/external/7182087657@sip.telnyx.com Standard HANGUP, cause: NORMAL_CLEARING
  135. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:846 (sofia/external/7182087657@sip.telnyx.com) State HANGUP going to sleep
  136. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:616 (sofia/external/7182087657@sip.telnyx.com) State Change CS_HANGUP -> CS_REPORTING
  137. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7182087657@sip.telnyx.com) Running State Change CS_REPORTING (Cur 1 Tot 6679)
  138. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:932 (sofia/external/7182087657@sip.telnyx.com) State REPORTING
  139. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:168 sofia/external/7182087657@sip.telnyx.com Standard REPORTING, cause: NORMAL_CLEARING
  140. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:932 (sofia/external/7182087657@sip.telnyx.com) State REPORTING going to sleep
  141. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:607 (sofia/external/7182087657@sip.telnyx.com) State Change CS_REPORTING -> CS_DESTROY
  142. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_session.c:1747 Session 6679 (sofia/external/7182087657@sip.telnyx.com) Locked, Waiting on external entities
  143. 2023-02-23 17:00:09.673479 98.20% [NOTICE] switch_core_session.c:1765 Session 6679 (sofia/external/7182087657@sip.telnyx.com) Ended
  144. 2023-02-23 17:00:09.673479 98.20% [NOTICE] switch_core_session.c:1769 Close Channel sofia/external/7182087657@sip.telnyx.com [CS_DESTROY]
  145. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:735 (sofia/external/7182087657@sip.telnyx.com) Running State Change CS_DESTROY (Cur 0 Tot 6679)
  146. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:745 (sofia/external/7182087657@sip.telnyx.com) State DESTROY
  147. 2023-02-23 17:00:09.673479 98.20% [DEBUG] mod_sofia.c:379 sofia/external/7182087657@sip.telnyx.com SOFIA DESTROY
  148. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:175 sofia/external/7182087657@sip.telnyx.com Standard DESTROY
  149. 2023-02-23 17:00:09.673479 98.20% [DEBUG] switch_core_state_machine.c:745 (sofia/external/7182087657@sip.telnyx.com) State DESTROY going to sleep
  150. freeswitch@freeswitch2> /exit
  151. [root@freeswitch2 ~]#

Reply to "Untitled"