From masked, 2 Years ago, written in Plain Text.
- view diff
Embed
  1.  
  2.  
  3.  
  4.  
  5.  
  6.  
  7.  
  8.  
  9.  
  10.  
  11.  
  12.  
  13.  
  14.  
  15.  
  16.  
  17.  
  18.  
  19.  
  20.  
  21.  
  22.  
  23.  
  24.  
  25.  
  26.  
  27.  
  28.  
  29.  
  30.  
  31.  
  32.  
  33.  
  34.  
  35.  
  36.  
  37.  
  38.  
  39.  
  40.  
  41.  
  42.  
  43.  
  44.  
  45.  
  46.  
  47.  
  48.  
  49.  
  50.  
  51.  
  52.  
  53.  
  54.  
  55.  
  56.  
  57.  
  58.  
  59.  
  60.  
  61.  
  62.  
  63.  
  64.  
  65.  
  66.  
  67.  
  68.  
  69.  
  70.  
  71.  
  72.  
  73.  
  74.  
  75.  
  76.  
  77.  
  78.  
  79.  
  80.  
  81.  
  82.  
  83.  
  84.  
  85.  
  86.  
  87.  
  88.  
  89.  
  90.  
  91.  
  92.  
  93.  
  94.  
  95.  
  96.  
  97.  
  98.  
  99.  
  100.  
  101.  
  102.  
  103.  
  104.  
  105.  
  106.  
  107.  
  108.  
  109.  
  110.  
  111.  
  112.  
  113.  
  114.  
  115.  
  116.  
  117.  
  118.  
  119.  
  120.  
  121.  
  122.  
  123.  
  124.  
  125.  
  126.  
  127.  
  128.  
  129.  
  130.  
  131.  
  132.  
  133.  
  134.  
  135.  
  136.  
  137.  
  138.  
  139.  
  140.  
  141.  
  142.  
  143.  
  144.  
  145.  
  146.  
  147.  
  148.  
  149.  
  150.  
  151.  
  152.  
  153.  
  154.  
  155.  
  156.  
  157.  
  158.  
  159.  
  160.  
  161.  
  162.  
  163.  
  164.  
  165.  
  166.  
  167.  
  168.  
  169.  
  170.  
  171.  
  172.  
  173.  
  174.  
  175.  
  176.  
  177.  
  178.  
  179.  
  180.  
  181.  
  182.  
  183.  
  184.  
  185.  
  186.  
  187.  
  188.  
  189.  
  190.  
  191.  
  192.  
  193.  
  194.  
  195.  
  196.  
  197.  
  198.  
  199.  
  200.  
  201.  
  202.  
  203.  
  204.  
  205.  
  206.  
  207.  
  208.  
  209. EXECUTE sofia/internal/pop@faith.ski set(voicemail_profile=default)
  210. 2016-08-05 23:55:28.118149 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [voicemail_profile]=[default]
  211. EXECUTE sofia/internal/pop@faith.ski lua(app.lua voicemail)
  212. 2016-08-05 23:55:28.118149 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x810ded0f0 Connected.
  213. 2016-08-05 23:55:28.141284 [DEBUG] mod_sofia.c:789 Disabling proxy mode due to call answer with no bridge
  214. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
  215. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  216. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  217. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [GSM:3:8000:20:13200:1]/[GSM:3:8000:20:13200:1]
  218. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [GSM:3:8000:20:13200:1] ++++ is saved as a match
  219. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
  220. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  221. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  222. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  223. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  224. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  225. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  226. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  227. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  228. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  229. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  230. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  231. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  232. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  233. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  234. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  235. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  236. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  237. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  238. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4281 Set telephone-event payload to 101@8000
  239. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:3091 Set Codec sofia/internal/pop@faith.ski GSM/8000 20 ms 160 samples 13200 bits 1 channels
  240. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_codec.c:111 sofia/internal/pop@faith.ski Original read codec set to GSM:3
  241. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4634 Set telephone-event payload to 101@8000
  242. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:4693 sofia/internal/pop@faith.ski Set 2833 dtmf send payload to 101 recv payload to 101
  243. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:6496 AUDIO RTP [sofia/internal/pop@faith.ski] 45.32.188.45 port 32448 -> 49.183.185.185 port 23804 codec: 3 ms: 20
  244. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  245. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]: START SESSION INITIALIZATION. sID=0.
  246. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]: ZID=326432306263326430343865.
  247. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]: Loading User's profile:
  248. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:    allowclear: OFF
  249. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:    autosecure: ON
  250. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:  disclose_bit: OFF
  251. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:  signal. role: Unknown
  252. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:           TTL: 4294967295
  253. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:   SAS schemes:
  254. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 B256
  255. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 B32  
  256. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439
  257. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:      Ciphers:
  258. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 AES3
  259. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 AES1
  260. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439
  261. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:    PK schemes:
  262. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 EC25
  263. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 DH3k
  264. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 DH2k
  265. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 Mult
  266. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439
  267. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:           ATL:
  268. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 HS32
  269. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 HS80
  270. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439
  271. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:       Hashes:
  272. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439 S256
  273. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439
  274. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]: Session initialization - DONE. sID=0.
  275.  
  276. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]: ATTACH NEW STREAM to sID=0:
  277. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [        zrtp]:   Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>.
  278. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:   Empty slot was found - initializing new stream with ID=0.
  279. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]:   Preparing ZRTP Hello according to the Session profile.
  280. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp main]: ATTACH NEW STREAM - DONE.
  281. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [   zrtp mitm]: START REGISTRATION STREAM ID=0 mode=CLEAR state=ACTIVE.
  282. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [ zrtp engine]: START STREAM ID=0 mode=CLEAR state=ACTIVE.
  283. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [        zrtp]:   Stream ID=0 CLEAR switching <ACTIVE> ---> <START>.
  284. 2016-08-05 23:55:28.141284 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52228 size=148. Stream 0:CLEAR:START
  285. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:6795 sofia/internal/pop@faith.ski Set 2833 dtmf send payload to 101
  286. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:6802 sofia/internal/pop@faith.ski Set 2833 dtmf receive payload to 101
  287. 2016-08-05 23:55:28.141284 [DEBUG] switch_core_media.c:6825 sofia/internal/pop@faith.ski Set rtp dtmf delay to 40
  288. 2016-08-05 23:55:28.141284 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/pop@faith.ski!
  289. 2016-08-05 23:55:28.141284 [DEBUG] switch_channel.c:3471 (sofia/internal/pop@faith.ski) Callstate Change RINGING -> EARLY
  290. 2016-08-05 23:55:28.141284 [DEBUG] mod_sofia.c:821 Local SDP sofia/internal/pop@faith.ski:
  291. v=0
  292. o=FreeSWITCH 1470372880 1470372881 IN IP4 45.32.188.45
  293. s=FreeSWITCH
  294. c=IN IP4 45.32.188.45
  295. t=0 0
  296. m=audio 32448 RTP/AVP 3 101
  297. a=rtpmap:3 GSM/8000
  298. a=rtpmap:101 telephone-event/8000
  299. a=fmtp:101 0-16
  300. a=ptime:20
  301. a=sendrecv
  302.  
  303. 2016-08-05 23:55:28.141284 [NOTICE] switch_cpp.cpp:686 Channel [sofia/internal/pop@faith.ski] has been answered
  304. 2016-08-05 23:55:28.141284 [DEBUG] switch_channel.c:3770 (sofia/internal/pop@faith.ski) Callstate Change EARLY -> ACTIVE
  305. EXECUTE sofia/internal/pop@faith.ski unbind_meta_app()
  306. 2016-08-05 23:55:28.141284 [INFO] switch_ivr_async.c:4065 UnBound A-Leg: ALL
  307. 2016-08-05 23:55:28.141284 [DEBUG] switch_cpp.cpp:746 CoreSession::setVariable('playback_terminators', '#')
  308. send 1058 bytes to udp/[49.183.185.185]:23510 at 23:55:28.161660:
  309.    ------------------------------------------------------------------------
  310.    SIP/2.0 200 OK
  311.    Via: SIP/2.0/UDP 49.183.185.185:23510;branch=z9hG4bK-524287-1---34d5b403f7e06f91;rport=23510
  312.    From: <sip:pop@faith.ski;transport=UDP>;tag=cf1c7915
  313.    To: <sip:masked@faith.ski;transport=UDP>;tag=B6vpNmmXDajmg
  314.    Call-ID: sWT2NxFucFKcIp0KDE9ivQ..
  315.    CSeq: 2 INVITE
  316.    Contact: <sip:masked@45.32.188.45:5060;transport=udp>
  317.    User-Agent: FreeSWITCH
  318.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  319.    Supported: timer, path, replaces
  320.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  321.    Content-Type: application/sdp
  322.    Content-Disposition: session
  323.    Content-Length: 219
  324.    Remote-Party-ID: "masked" <sip:masked@faith.ski>;party=calling;privacy=off;screen=no
  325.    
  326.    v=0
  327.    o=FreeSWITCH 1470372880 1470372881 IN IP4 45.32.188.45
  328.    s=FreeSWITCH
  329.    c=IN IP4 45.32.188.45
  330.    t=0 0
  331.    m=audio 32448 RTP/AVP 3 101
  332.    a=rtpmap:3 GSM/8000
  333.    a=rtpmap:101 telephone-event/8000
  334.    a=fmtp:101 0-16
  335.    a=ptime:20
  336.    ------------------------------------------------------------------------
  337. EXECUTE sofia/internal/pop@faith.ski playback(silence_stream://200)
  338. 2016-08-05 23:55:28.161816 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  339. 2016-08-05 23:55:28.161816 [DEBUG] sofia.c:6939 Channel sofia/internal/pop@faith.ski entering state [completed][200]
  340. 2016-08-05 23:55:28.217780 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52229 size=148. Stream 0:CLEAR:START
  341. 2016-08-05 23:55:28.317601 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52230 size=148. Stream 0:CLEAR:START
  342. 2016-08-05 23:55:28.337974 [DEBUG] switch_ivr_play_say.c:1910 done playing file silence_stream://200
  343. 2016-08-05 23:55:28.337974 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  344. recv 429 bytes from udp/[49.183.185.185]:23510 at 23:55:28.343470:
  345.    ------------------------------------------------------------------------
  346.    ACK sip:masked@45.32.188.45:5060;transport=udp SIP/2.0
  347.    Via: SIP/2.0/UDP 49.183.185.185:23510;branch=z9hG4bK-524287-1---bceeb08953c12a58;rport
  348.    Max-Forwards: 70
  349.    Contact: <sip:pop@49.183.185.185:23510;transport=UDP>
  350.    To: <sip:masked@faith.ski;transport=UDP>;tag=B6vpNmmXDajmg
  351.    From: <sip:pop@faith.ski;transport=UDP>;tag=cf1c7915
  352.    Call-ID: sWT2NxFucFKcIp0KDE9ivQ..
  353.    CSeq: 2 ACK
  354.    User-Agent: Zoiper r55b5166
  355.    Content-Length: 0
  356.    
  357.    ------------------------------------------------------------------------
  358. 2016-08-05 23:55:28.357524 [DEBUG] sofia.c:6939 Channel sofia/internal/pop@faith.ski entering state [ready][200]
  359. 2016-08-05 23:55:28.538164 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52231 size=148. Stream 0:CLEAR:START
  360. 2016-08-05 23:55:28.717658 [DEBUG] switch_rtp.c:6711 Correct audio ip/port confirmed.
  361. 2016-08-05 23:55:28.758112 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52232 size=148. Stream 0:CLEAR:START
  362. 2016-08-05 23:55:28.978164 [DEBUG] switch_rtp.c:1439  [ zrtp engine]: WARNING! HELLO have been resent 5 times without a response. Raising ZRTP_EVENT_NO_ZRTP_QUICK event. ID=0
  363. 2016-08-05 23:55:28.978164 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52233 size=148. Stream 0:CLEAR:START
  364. 2016-08-05 23:55:29.198104 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52234 size=148. Stream 0:CLEAR:START
  365. 2016-08-05 23:55:29.417498 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52235 size=148. Stream 0:CLEAR:START
  366. 2016-08-05 23:55:29.637457 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52236 size=148. Stream 0:CLEAR:START
  367. 2016-08-05 23:55:29.698125 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav
  368. 2016-08-05 23:55:29.698125 [DEBUG] switch_ivr.c:3553 No language specified - Using [en]
  369. 2016-08-05 23:55:29.698125 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  370. 2016-08-05 23:55:29.858139 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52237 size=148. Stream 0:CLEAR:START
  371. 2016-08-05 23:55:30.058211 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52238 size=148. Stream 0:CLEAR:START
  372. 2016-08-05 23:55:30.278168 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52239 size=148. Stream 0:CLEAR:START
  373. 2016-08-05 23:55:30.498095 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52240 size=148. Stream 0:CLEAR:START
  374. 2016-08-05 23:55:30.698154 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52241 size=148. Stream 0:CLEAR:START
  375. 2016-08-05 23:55:30.898180 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52242 size=148. Stream 0:CLEAR:START
  376. 2016-08-05 23:55:31.118148 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52243 size=148. Stream 0:CLEAR:START
  377. 2016-08-05 23:55:31.338178 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52244 size=148. Stream 0:CLEAR:START
  378. 2016-08-05 23:55:31.537336 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52245 size=148. Stream 0:CLEAR:START
  379. 2016-08-05 23:55:31.738179 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52246 size=148. Stream 0:CLEAR:START
  380. 2016-08-05 23:55:31.878063 [DEBUG] switch_ivr_play_say.c:1910 done playing file file_string://digits/6.wav!digits/9.wav!digits/6.wav!digits/9.wav
  381. 2016-08-05 23:55:31.878063 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  382. 2016-08-05 23:55:31.938027 [DEBUG] switch_rtp.c:1439  [  zrtp utils]:   Send <HELLO> ssrc=1752845048 seq=52247 size=148. Stream 0:CLEAR:START
  383. 2016-08-05 23:55:32.158113 [DEBUG] switch_rtp.c:1439  [ zrtp engine]: WARNING! HELLO Max retransmissions count reached (20 retries). ID=0
  384. 2016-08-05 23:55:32.158113 [DEBUG] switch_rtp.c:1439  [        zrtp]:   Stream ID=0 CLEAR switching <START> ---> <NOZRTP>.
  385. 2016-08-05 23:55:32.858192 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-not_available.wav
  386. 2016-08-05 23:55:33.078135 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  387. 2016-08-05 23:55:33.078135 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  388. 2016-08-05 23:55:37.678108 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-record_message.wav
  389. 2016-08-05 23:55:37.778113 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  390. 2016-08-05 23:55:38.798113 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  391. 2016-08-05 23:55:38.798113 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  392. 2016-08-05 23:55:39.797960 [DEBUG] switch_ivr_play_say.c:1910 done playing file tone_stream://L=1;%(1000, 0, 640)
  393. 2016-08-05 23:55:39.898109 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  394. 2016-08-05 23:55:39.898109 [DEBUG] switch_ivr_play_say.c:559 Raw Codec Activated, ready to waste resources!
  395. 2016-08-05 23:55:39.898109 [DEBUG] switch_ivr_play_say.c:673 Raw Codec Activated
  396. 2016-08-05 23:55:39.898109 [DEBUG] switch_core_codec.c:221 sofia/internal/pop@faith.ski Push codec L16:100
  397. 2016-08-05 23:55:44.897304 [DEBUG] switch_core_codec.c:246 sofia/internal/pop@faith.ski Restore previous codec GSM:3.
  398. 2016-08-05 23:55:44.897304 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  399. 2016-08-05 23:55:46.118137 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-listen_to_recording.wav
  400. 2016-08-05 23:55:46.118137 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  401. 2016-08-05 23:55:46.518203 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
  402. 2016-08-05 23:55:46.518203 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  403. 2016-08-05 23:55:46.978077 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/1.wav
  404. 2016-08-05 23:55:47.098101 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  405. 2016-08-05 23:55:47.098101 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  406. 2016-08-05 23:55:48.238060 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-save_recording.wav
  407. 2016-08-05 23:55:48.238060 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  408. 2016-08-05 23:55:48.637311 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
  409. 2016-08-05 23:55:48.637311 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  410. 2016-08-05 23:55:49.038138 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/2.wav
  411. 2016-08-05 23:55:49.158172 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  412. 2016-08-05 23:55:49.158172 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  413. 2016-08-05 23:55:50.038028 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-rerecord.wav
  414. 2016-08-05 23:55:50.038028 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  415. 2016-08-05 23:55:50.438135 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
  416. 2016-08-05 23:55:50.438135 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  417. 2016-08-05 23:55:50.838181 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/3.wav
  418. 2016-08-05 23:55:53.858111 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  419. 2016-08-05 23:55:53.858111 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  420. 2016-08-05 23:55:55.078077 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-listen_to_recording.wav
  421. 2016-08-05 23:55:55.078077 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  422. 2016-08-05 23:55:55.478150 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
  423. 2016-08-05 23:55:55.478150 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  424. 2016-08-05 23:55:55.938123 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/1.wav
  425. 2016-08-05 23:55:56.038126 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  426. 2016-08-05 23:55:56.038126 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  427. send 881 bytes to tls/[119.9.12.222]:5061 at 23:55:56.042048:
  428.    ------------------------------------------------------------------------
  429.    REGISTER sip:sip.au.didlogic.net;transport=tls SIP/2.0
  430.    Via: SIP/2.0/TLS 45.32.188.45:5081;rport;branch=z9hG4bK32yKB6Nym1m4H
  431.    Max-Forwards: 70
  432.    From: <sip:19423@sip.au.didlogic.net>;tag=te8cNUUj3reyH
  433.    To: <sip:19423@sip.au.didlogic.net>
  434.    Call-ID: f04031ee-0a5b-e611-a0a3-8f57d09e751d
  435.    CSeq: 94864615 REGISTER
  436.    Contact: <sip:19423@45.32.188.45:5081;transport=tls;transport=tls;gw=12e36ae0-b768-4707-acd5-3b91d228c59a>
  437.    Expires: 800
  438.    User-Agent: FreeSWITCH
  439.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  440.    Supported: timer, path, replaces
  441.    Authorization: Digest username="19423", realm="sip.au.didlogic.net", nonce="V6SbQlekmhaDSa/iG8A5EHii4f6993FtSYNer4A=", cnonce="xnRLgdWtEjS4mMfaZ2pXZA", algorithm=MD5, uri="sip:sip.au.didlogic.net;transport=tls", response="801a493246aa7c757801079e5d18c52b", qop=auth, nc=00000014
  442.    Content-Length: 0
  443.    
  444.    ------------------------------------------------------------------------
  445. recv 511 bytes from tls/[119.9.12.222]:5061 at 23:55:56.069758:
  446.    ------------------------------------------------------------------------
  447.    SIP/2.0 200 OK
  448.    Via: SIP/2.0/TLS 45.32.188.45:5081;rport=41810;branch=z9hG4bK32yKB6Nym1m4H;received=45.32.188.45
  449.    From: <sip:19423@sip.au.didlogic.net>;tag=te8cNUUj3reyH
  450.    To: <sip:19423@sip.au.didlogic.net>;tag=b27e1a1d33761e85846fc98f5f3a7e58.82f2
  451.    Call-ID: f04031ee-0a5b-e611-a0a3-8f57d09e751d
  452.    CSeq: 94864615 REGISTER
  453.    Contact: <sip:19423@45.32.188.45:5081;transport=tls;transport=tls;gw=12e36ae0-b768-4707-acd5-3b91d228c59a>;expires=800;received="sip:45.32.188.45:41810;transport=TLS"
  454.    Content-Length: 0
  455.    
  456.    ------------------------------------------------------------------------
  457. 2016-08-05 23:55:57.176991 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-save_recording.wav
  458. 2016-08-05 23:55:57.176991 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  459. 2016-08-05 23:55:57.577762 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
  460. 2016-08-05 23:55:57.577762 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  461. 2016-08-05 23:55:57.978220 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/2.wav
  462. 2016-08-05 23:55:58.098148 [DEBUG] switch_cpp.cpp:890 getDigits dtmf_buf:
  463. 2016-08-05 23:55:58.098148 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  464. recv 427 bytes from udp/[163.172.202.74]:5061 at 23:55:58.633128:
  465.    ------------------------------------------------------------------------
  466.    REGISTER sip:45.32.188.45:5060 SIP/2.0
  467.    Via: SIP/2.0/UDP 163.172.202.74:5061;branch=z9hG4bK406631864a3021ed57a49a8d;rport
  468.    From: "2314" <sip:2314@45.32.188.45:5060>;tag=406631864a4ef
  469.    To: "2314" <sip:2314@45.32.188.45:5060>
  470.    Call-ID: 1864a302-59a01ed-57a49a8d@45.32.188.45
  471.    CSeq: 1 REGISTER
  472.    Contact: "2314" <sip:2314@163.172.202.74:5061>
  473.    User-Agent: VaxSIPUserAgent/3.1
  474.    Expires: 1800
  475.    Max-Forwards: 70
  476.    Content-Length: 0
  477.    
  478.    ------------------------------------------------------------------------
  479. 2016-08-05 23:55:58.618124 [WARNING] sofia_reg.c:1787 SIP auth challenge (REGISTER) on sofia profile 'internal' for [2314@45.32.188.45] from ip 163.172.202.74
  480. send 610 bytes to udp/[163.172.202.74]:5061 at 23:55:58.634999:
  481.    ------------------------------------------------------------------------
  482.    SIP/2.0 401 Unauthorized
  483.    Via: SIP/2.0/UDP 163.172.202.74:5061;branch=z9hG4bK406631864a3021ed57a49a8d;rport=5061
  484.    From: "2314" <sip:2314@45.32.188.45:5060>;tag=406631864a4ef
  485.    To: "2314" <sip:2314@45.32.188.45:5060>;tag=S4yHeF0e569Sj
  486.    Call-ID: 1864a302-59a01ed-57a49a8d@45.32.188.45
  487.    CSeq: 1 REGISTER
  488.    User-Agent: FreeSWITCH
  489.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  490.    Supported: timer, path, replaces
  491.    WWW-Authenticate: Digest realm="45.32.188.45", nonce="d0dd4656-145b-e611-a0a3-8f57d09e751d", algorithm=MD5, qop="auth"
  492.    Content-Length: 0
  493.    
  494.    ------------------------------------------------------------------------
  495. 2016-08-05 23:55:58.977376 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-rerecord.wav
  496. 2016-08-05 23:55:58.977376 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  497. recv 660 bytes from udp/[163.172.202.74]:5061 at 23:55:59.005775:
  498.    ------------------------------------------------------------------------
  499.    REGISTER sip:45.32.188.45:5060 SIP/2.0
  500.    Via: SIP/2.0/UDP 163.172.202.74:5061;branch=z9hG4bK406641864a4781f057a49a8e;rport
  501.    From: "2314" <sip:2314@45.32.188.45:5060>;tag=406641864a668
  502.    To: "2314" <sip:2314@45.32.188.45:5060>
  503.    Call-ID: 1864a302-59a01ed-57a49a8d@45.32.188.45
  504.    CSeq: 2 REGISTER
  505.    Contact: "2314" <sip:2314@163.172.202.74:5061>
  506.    Authorization: Digest username="2314", realm="45.32.188.45", nonce="d0dd4656-145b-e611-a0a3-8f57d09e751d", uri="sip:45.32.188.45", response="439507879752bb5999a3e395a7792424", algorithm=MD5, cnonce="1864a478", qop=auth, nc=00000002
  507.    User-Agent: VaxSIPUserAgent/3.1
  508.    Expires: 1800
  509.    Max-Forwards: 70
  510.    Content-Length: 0
  511.    
  512.    ------------------------------------------------------------------------
  513. 2016-08-05 23:55:58.998221 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x808df70f0 Connected.
  514. 2016-08-05 23:55:59.018886 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x810e7a0f0 Connected.
  515. 2016-08-05 23:55:59.018886 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x810e7a0f0 released.
  516. 2016-08-05 23:55:59.018886 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x810e7a0f0 Connected.
  517. 2016-08-05 23:55:59.018886 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x810e7a0f0 released.
  518. 2016-08-05 23:55:59.018886 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x808df70f0 released.
  519. 2016-08-05 23:55:59.018886 [WARNING] sofia_reg.c:2901 Can't find user [2314@45.32.188.45] from 163.172.202.74
  520. You must define a domain called '45.32.188.45' in your directory and add a user with the id="2314" attribute
  521. and you must configure your device to use the proper domain in it's authentication credentials.
  522. 2016-08-05 23:55:59.018886 [WARNING] sofia_reg.c:1732 SIP auth failure (REGISTER) on sofia profile 'internal' for [2314@45.32.188.45] from ip 163.172.202.74
  523. send 487 bytes to udp/[163.172.202.74]:5061 at 23:55:59.024255:
  524.    ------------------------------------------------------------------------
  525.    SIP/2.0 403 Forbidden
  526.    Via: SIP/2.0/UDP 163.172.202.74:5061;branch=z9hG4bK406641864a4781f057a49a8e;rport=5061
  527.    From: "2314" <sip:2314@45.32.188.45:5060>;tag=406641864a668
  528.    To: "2314" <sip:2314@45.32.188.45:5060>;tag=tDragaHj2F0ce
  529.    Call-ID: 1864a302-59a01ed-57a49a8d@45.32.188.45
  530.    CSeq: 2 REGISTER
  531.    User-Agent: FreeSWITCH
  532.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  533.    Supported: timer, path, replaces
  534.    Content-Length: 0
  535.    
  536.    ------------------------------------------------------------------------
  537. 2016-08-05 23:55:59.378073 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
  538. 2016-08-05 23:55:59.378073 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
  539. 2016-08-05 23:55:59.778129 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/3.wav
  540. freeswitch@sip>
  541. [sip][      0-$ csh  (1*$ csh)  2$ csh  3$ csh  4$ csh      ][08/05/16 11:56 PM]
  542. 2016-08-05 23:56:49.938152 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [forward_all_destination]=[UNDEF]
  543. EXECUTE sofia/internal/pop@faith.ski set(forward_busy_enabled=)
  544. 2016-08-05 23:56:49.938152 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [forward_busy_enabled]=[UNDEF]
  545. EXECUTE sofia/internal/pop@faith.ski set(forward_busy_destination=)
  546. 2016-08-05 23:56:49.938152 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [forward_busy_destination]=[UNDEF]
  547. EXECUTE sofia/internal/pop@faith.ski set(forward_no_answer_enabled=)
  548. 2016-08-05 23:56:49.938152 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [forward_no_answer_enabled]=[UNDEF]
  549. EXECUTE sofia/internal/pop@faith.ski set(forward_no_answer_destination=)
  550. 2016-08-05 23:56:49.938152 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [forward_no_answer_destination]=[UNDEF]
  551. EXECUTE sofia/internal/pop@faith.ski set(forward_user_not_registered_enabled=)
  552. 2016-08-05 23:56:49.957851 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [forward_user_not_registered_enabled]=[UNDEF]
  553. EXECUTE sofia/internal/pop@faith.ski set(forward_user_not_registered_destination=)
  554. 2016-08-05 23:56:49.957851 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [forward_user_not_registered_destination]=[UNDEF]
  555. EXECUTE sofia/internal/pop@faith.ski set(do_not_disturb=)
  556. 2016-08-05 23:56:49.957851 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [do_not_disturb]=[UNDEF]
  557. EXECUTE sofia/internal/pop@faith.ski set(call_timeout=30)
  558. 2016-08-05 23:56:49.957851 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [call_timeout]=[30]
  559. EXECUTE sofia/internal/pop@faith.ski set(missed_call_app=)
  560. 2016-08-05 23:56:49.957851 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [missed_call_app]=[UNDEF]
  561. EXECUTE sofia/internal/pop@faith.ski set(missed_call_data=)
  562. 2016-08-05 23:56:49.978050 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [missed_call_data]=[UNDEF]
  563. EXECUTE sofia/internal/pop@faith.ski set(call_direction=local)
  564. 2016-08-05 23:56:49.978050 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [call_direction]=[local]
  565. EXECUTE sofia/internal/pop@faith.ski export(origination_callee_id_name=masked)
  566. 2016-08-05 23:56:49.978050 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[masked]
  567. EXECUTE sofia/internal/pop@faith.ski set(RFC2822_DATE=Fri, 05 Aug 2016 23:56:49 +1000)
  568. 2016-08-05 23:56:49.978050 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [RFC2822_DATE]=[Fri, 05 Aug 2016 23:56:49 +1000]
  569. EXECUTE sofia/internal/pop@faith.ski hash(insert/faith.ski-last_dial/pop/masked)
  570. EXECUTE sofia/internal/pop@faith.ski eval(not_secure)
  571. EXECUTE sofia/internal/pop@faith.ski limit(hash faith.ski masked 5 )
  572. 2016-08-05 23:56:49.978050 [DEBUG] switch_limit.c:126 incr called: faith.ski_masked max:5, interval:0
  573. 2016-08-05 23:56:49.978050 [DEBUG] mod_hash.c:196 Usage for faith.ski_masked is now 1/5
  574. EXECUTE sofia/internal/pop@faith.ski bind_digit_action(local,*1,exec:execute_extension,dx XML faith.ski,both)
  575. 2016-08-05 23:56:49.978050 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
  576. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x80b014dd0 data: 0x808d07728
  577. 2016-08-05 23:56:49.978050 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
  578. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x80b014dd0 data: 0x808d07798
  579. EXECUTE sofia/internal/pop@faith.ski bind_digit_action(local,*2,exec:record_session,/usr/local/freeswitch/recordings/faith.ski/archive/2016/Aug/05/7728a874-145b-e611-a0a3-8f57d09e751d.wav,both)
  580. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x80b014dd0 data: 0x808d079d0
  581. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x80b014dd0 data: 0x808d07a90
  582. EXECUTE sofia/internal/pop@faith.ski bind_digit_action(local,*3,exec:execute_extension,cf XML faith.ski,both)
  583. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x80b014dd0 data: 0x808d07c10
  584. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x80b014dd0 data: 0x808d07c80
  585. EXECUTE sofia/internal/pop@faith.ski bind_digit_action(local,*4,exec:execute_extension,att_xfer XML faith.ski,both)
  586. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x80b014dd0 data: 0x808d07dc0
  587. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x80b014dd0 data: 0x808d07e30
  588. EXECUTE sofia/internal/pop@faith.ski digit_action_set_realm(local)
  589. 2016-08-05 23:56:49.978050 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
  590. EXECUTE sofia/internal/pop@faith.ski set(hangup_after_bridge=true)
  591. 2016-08-05 23:56:49.978050 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [hangup_after_bridge]=[true]
  592. EXECUTE sofia/internal/pop@faith.ski set(continue_on_fail=true)
  593. 2016-08-05 23:56:49.978050 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [continue_on_fail]=[true]
  594. EXECUTE sofia/internal/pop@faith.ski hash(insert/faith.ski-call_return/masked/pop)
  595. EXECUTE sofia/internal/pop@faith.ski hash(insert/faith.ski-last_dial_ext/masked/7728a874-145b-e611-a0a3-8f57d09e751d)
  596. EXECUTE sofia/internal/pop@faith.ski set(called_party_call_group=)
  597. 2016-08-05 23:56:49.978050 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [called_party_call_group]=[UNDEF]
  598. EXECUTE sofia/internal/pop@faith.ski hash(insert/faith.ski-last_dial//7728a874-145b-e611-a0a3-8f57d09e751d)
  599. EXECUTE sofia/internal/pop@faith.ski set(api_hangup_hook=lua app.lua hangup)
  600. 2016-08-05 23:56:49.978050 [DEBUG] mod_dptools.c:1519 SET sofia/internal/pop@faith.ski [api_hangup_hook]=[lua app.lua hangup]
  601. EXECUTE sofia/internal/pop@faith.ski bridge(user/masked@faith.ski)
  602. 2016-08-05 23:56:49.978050 [DEBUG] switch_channel.c:1250 sofia/internal/pop@faith.ski EXPORTING[export_vars] [domain_name]=[faith.ski] to event
  603. 2016-08-05 23:56:49.978050 [DEBUG] switch_channel.c:1250 sofia/internal/pop@faith.ski EXPORTING[export_vars] [dialed_extension]=[masked] to event
  604. 2016-08-05 23:56:49.978050 [DEBUG] switch_channel.c:1250 sofia/internal/pop@faith.ski EXPORTING[export_vars] [origination_callee_id_name]=[masked] to event
  605. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  606. 2016-08-05 23:56:49.978050 [DEBUG] switch_channel.c:1250 sofia/internal/pop@faith.ski EXPORTING[export_vars] [domain_name]=[faith.ski] to event
  607. 2016-08-05 23:56:49.978050 [DEBUG] switch_channel.c:1250 sofia/internal/pop@faith.ski EXPORTING[export_vars] [dialed_extension]=[masked] to event
  608. 2016-08-05 23:56:49.978050 [DEBUG] switch_channel.c:1250 sofia/internal/pop@faith.ski EXPORTING[export_vars] [origination_callee_id_name]=[masked] to event
  609. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  610. 2016-08-05 23:56:49.978050 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/masked@1.152.97.29:6517 [17a6e374-145b-e611-a0a3-8f57d09e751d]
  611. 2016-08-05 23:56:49.978050 [DEBUG] mod_sofia.c:4757 (sofia/internal/masked@1.152.97.29:6517) State Change CS_NEW -> CS_INIT
  612. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/masked@1.152.97.29:6517) Running State Change CS_INIT
  613. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/masked@1.152.97.29:6517) State INIT
  614. 2016-08-05 23:56:49.978050 [DEBUG] mod_sofia.c:89 sofia/internal/masked@1.152.97.29:6517 SOFIA INIT
  615. 2016-08-05 23:56:49.978050 [DEBUG] sofia_glue.c:1257 sofia/internal/masked@1.152.97.29:6517 sending invite version: 1.7.0 git ce087fc 2016-06-23 21:07:31Z 64bit
  616. Local SDP:
  617. v=0
  618. o=Zoiper 0 0 IN IP4 49.183.185.185
  619. s=Zoiper
  620. c=IN IP4 49.183.185.185
  621. t=0 0
  622. m=audio 23808 RTP/AVP 3 0 8 9 101
  623. a=rtpmap:3 GSM/8000
  624. a=rtpmap:0 PCMU/8000
  625. a=rtpmap:8 PCMA/8000
  626. a=rtpmap:9 G722/8000
  627. a=rtpmap:101 telephone-event/8000
  628. a=fmtp:101 0-16
  629.  
  630. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:40 sofia/internal/masked@1.152.97.29:6517 Standard INIT
  631. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/masked@1.152.97.29:6517) State Change CS_INIT -> CS_ROUTING
  632. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/masked@1.152.97.29:6517) State INIT going to sleep
  633. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/masked@1.152.97.29:6517) Running State Change CS_ROUTING
  634. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/masked@1.152.97.29:6517) State ROUTING
  635. 2016-08-05 23:56:49.978050 [DEBUG] mod_sofia.c:142 sofia/internal/masked@1.152.97.29:6517 SOFIA ROUTING
  636. 2016-08-05 23:56:49.978050 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/masked@1.152.97.29:6517) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  637. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/masked@1.152.97.29:6517) State ROUTING going to sleep
  638. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/masked@1.152.97.29:6517) Running State Change CS_CONSUME_MEDIA
  639. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/masked@1.152.97.29:6517) State CONSUME_MEDIA
  640. 2016-08-05 23:56:49.978050 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/masked@1.152.97.29:6517) State CONSUME_MEDIA going to sleep
  641. send 1246 bytes to udp/[1.152.97.29]:6517 at 23:56:49.994759:
  642.    ------------------------------------------------------------------------
  643.    INVITE sip:masked@1.152.97.29:6517;transport=UDP;rinstance=9418840bbb26689f SIP/2.0
  644.    Via: SIP/2.0/UDP 45.32.188.45;rport;branch=z9hG4bKFZHF1Uv6yea6j
  645.    Max-Forwards: 69
  646.    From: "pop" <sip:pop@faith.ski>;tag=9mKya0D7pNe5B
  647.    To: <sip:masked@1.152.97.29:6517;transport=UDP;rinstance=9418840bbb26689f>
  648.    Call-ID: 4c422925-d5b7-1234-98b8-c7da676a5764
  649.    CSeq: 94866640 INVITE
  650.    Contact: <sip:mod_sofia@45.32.188.45:5060>
  651.    User-Agent: FreeSWITCH
  652.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  653.    Supported: timer, path, replaces
  654.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  655.    Content-Type: application/sdp
  656.    Content-Disposition: session
  657.    Content-Length: 293
  658.    X-FS-Support: update_display,send_info
  659.    Remote-Party-ID: "pop" <sip:pop@faith.ski>;party=calling;screen=yes;privacy=off
  660.    
  661.    v=0
  662.    o=Zoiper 4357671033347185306 4173376853073507121 IN IP4 49.183.185.185
  663.    s=Zoiper
  664.    c=IN IP4 49.183.185.185
  665.    t=0 0
  666.    m=audio 23808 RTP/AVP 3 0 8 9 101
  667.    a=rtpmap:3 GSM/8000
  668.    a=rtpmap:0 PCMU/8000
  669.    a=rtpmap:8 PCMA/8000
  670.    a=rtpmap:9 G722/8000
  671.    a=rtpmap:101 telephone-event/8000
  672.    a=fmtp:101 0-16
  673.    ------------------------------------------------------------------------
  674. 2016-08-05 23:56:49.978050 [DEBUG] sofia.c:6939 Channel sofia/internal/masked@1.152.97.29:6517 entering state [calling][0]
  675. recv 308 bytes from udp/[1.152.97.29]:6517 at 23:56:50.957057:
  676.    ------------------------------------------------------------------------
  677.    SIP/2.0 100 Trying
  678.    Via: SIP/2.0/UDP 45.32.188.45;rport=5060;branch=z9hG4bKFZHF1Uv6yea6j
  679.    To: <sip:masked@1.152.97.29:6517;transport=UDP;rinstance=9418840bbb26689f>
  680.    From: "pop" <sip:pop@faith.ski>;tag=9mKya0D7pNe5B
  681.    Call-ID: 4c422925-d5b7-1234-98b8-c7da676a5764
  682.    CSeq: 94866640 INVITE
  683.    Content-Length: 0
  684.    
  685.    ------------------------------------------------------------------------
  686. recv 441 bytes from udp/[1.152.97.29]:6517 at 23:56:51.157978:
  687.    ------------------------------------------------------------------------
  688.    SIP/2.0 180 Ringing
  689.    Via: SIP/2.0/UDP 45.32.188.45;rport=5060;branch=z9hG4bKFZHF1Uv6yea6j
  690.    Contact: <sip:masked@1.152.97.29:6517;transport=UDP>
  691.    To: <sip:masked@1.152.97.29:6517;transport=UDP;rinstance=9418840bbb26689f>;tag=81efd82f
  692.    From: "pop" <sip:pop@faith.ski>;tag=9mKya0D7pNe5B
  693.    Call-ID: 4c422925-d5b7-1234-98b8-c7da676a5764
  694.    CSeq: 94866640 INVITE
  695.    User-Agent: Zoiper r55b5166
  696.    Allow-Events: presence, kpml, talk
  697.    Content-Length: 0
  698.    
  699.    ------------------------------------------------------------------------
  700. 2016-08-05 23:56:51.157074 [DEBUG] sofia.c:6939 Channel sofia/internal/masked@1.152.97.29:6517 entering state [proceeding][180]
  701. 2016-08-05 23:56:51.157074 [NOTICE] sofia.c:7047 Ring-Ready sofia/internal/masked@1.152.97.29:6517!
  702. 2016-08-05 23:56:51.157074 [DEBUG] switch_channel.c:3343 (sofia/internal/masked@1.152.97.29:6517) Callstate Change DOWN -> RINGING
  703. 2016-08-05 23:56:51.157074 [NOTICE] mod_sofia.c:2220 Ring-Ready sofia/internal/pop@faith.ski!
  704. 2016-08-05 23:56:51.157074 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/pop@faith.ski!
  705. send 806 bytes to udp/[49.183.185.185]:23510 at 23:56:51.166333:
  706.    ------------------------------------------------------------------------
  707.    SIP/2.0 180 Ringing
  708.    Via: SIP/2.0/UDP 49.183.185.185:23510;branch=z9hG4bK-524287-1---0415a7d6262ece37;rport=23510
  709.    From: <sip:pop@faith.ski;transport=UDP>;tag=6be5232a
  710.    To: <sip:masked@faith.ski;transport=UDP>;tag=8Bt584v3Scrjg
  711.    Call-ID: KUzX0zgTmklc6ZVhY5TgKw..
  712.    CSeq: 2 INVITE
  713.    Contact: <sip:masked@45.32.188.45:5060;transport=udp>
  714.    User-Agent: FreeSWITCH
  715.    Accept: application/sdp
  716.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  717.    Supported: timer, path, replaces
  718.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  719.    Content-Length: 0
  720.    Remote-Party-ID: "masked" <sip:masked@faith.ski>;party=calling;privacy=off;screen=no
  721.    
  722.    ------------------------------------------------------------------------
  723. 2016-08-05 23:56:51.177059 [DEBUG] sofia.c:6939 Channel sofia/internal/pop@faith.ski entering state [early][180]
  724. recv 917 bytes from udp/[1.152.97.29]:6517 at 23:56:52.780212:
  725.    ------------------------------------------------------------------------
  726.    SIP/2.0 200 OK
  727.    Via: SIP/2.0/UDP 45.32.188.45;rport=5060;branch=z9hG4bKFZHF1Uv6yea6j
  728.    Contact: <sip:masked@1.152.97.29:6517;transport=UDP>
  729.    To: <sip:masked@1.152.97.29:6517;transport=UDP;rinstance=9418840bbb26689f>;tag=81efd82f
  730.    From: "pop" <sip:pop@faith.ski>;tag=9mKya0D7pNe5B
  731.    Call-ID: 4c422925-d5b7-1234-98b8-c7da676a5764
  732.    CSeq: 94866640 INVITE
  733.    Content-Type: application/sdp
  734.    User-Agent: Zoiper r55b5166
  735.    Allow-Events: presence, kpml, talk
  736.    Content-Length: 448
  737.    
  738.    v=0
  739.    o=Zoiper 0 1 IN IP4 10.225.191.196
  740.    s=Zoiper
  741.    c=IN IP4 10.225.191.196
  742.    t=0 0
  743.    m=audio 38176 RTP/AVP 3 106 0 8 9 102 97 101
  744.    a=rtpmap:3 GSM/8000
  745.    a=rtpmap:106 opus/48000/2
  746.    a=fmtp:106 minptime=20; cbr=1; maxaveragebitrate=40000; useinbandfec=1
  747.    a=rtpmap:0 PCMU/8000
  748.    a=rtpmap:8 PCMA/8000
  749.    a=rtpmap:9 G722/8000
  750.    a=rtpmap:102 G726-32/8000
  751.    a=rtpmap:97 iLBC/8000
  752.    a=fmtp:97 mode=30
  753.    a=rtpmap:101 telephone-event/8000
  754.    a=fmtp:101 0-16
  755.    a=sendrecv
  756.    ------------------------------------------------------------------------
  757. 2016-08-05 23:56:52.778023 [DEBUG] sofia.c:6939 Channel sofia/internal/masked@1.152.97.29:6517 entering state [completing][200]
  758. 2016-08-05 23:56:52.778023 [DEBUG] sofia.c:6949 Remote SDP:
  759. v=0
  760. o=Zoiper 0 1 IN IP4 10.225.191.196
  761. s=Zoiper
  762. c=IN IP4 10.225.191.196
  763. t=0 0
  764. m=audio 38176 RTP/AVP 3 106 0 8 9 102 97 101
  765. a=rtpmap:3 GSM/8000
  766. a=rtpmap:106 opus/48000/2
  767. a=fmtp:106 minptime=20; cbr=1; maxaveragebitrate=40000; useinbandfec=1
  768. a=rtpmap:0 PCMU/8000
  769. a=rtpmap:8 PCMA/8000
  770. a=rtpmap:9 G722/8000
  771. a=rtpmap:102 G726-32/8000
  772. a=rtpmap:97 iLBC/8000
  773. a=fmtp:97 mode=30
  774. a=rtpmap:101 telephone-event/8000
  775. a=fmtp:101 0-16
  776.  
  777. send 410 bytes to udp/[1.152.97.29]:6517 at 23:56:52.785838:
  778.    ------------------------------------------------------------------------
  779.    ACK sip:masked@1.152.97.29:6517;transport=UDP SIP/2.0
  780.    Via: SIP/2.0/UDP 45.32.188.45;rport;branch=z9hG4bKg8a82pDavQ0re
  781.    Max-Forwards: 70
  782.    From: "pop" <sip:pop@faith.ski>;tag=9mKya0D7pNe5B
  783.    To: <sip:masked@1.152.97.29:6517;transport=UDP;rinstance=9418840bbb26689f>;tag=81efd82f
  784.    Call-ID: 4c422925-d5b7-1234-98b8-c7da676a5764
  785.    CSeq: 94866640 ACK
  786.    Contact: <sip:mod_sofia@45.32.188.45:5060>
  787.    Content-Length: 0
  788.    
  789.    ------------------------------------------------------------------------
  790. 2016-08-05 23:56:52.778023 [DEBUG] sofia.c:6939 Channel sofia/internal/masked@1.152.97.29:6517 entering state [ready][200]
  791. 2016-08-05 23:56:52.778023 [NOTICE] sofia.c:7932 Channel [sofia/internal/masked@1.152.97.29:6517] has been answered
  792. 2016-08-05 23:56:52.778023 [DEBUG] switch_channel.c:3770 (sofia/internal/masked@1.152.97.29:6517) Callstate Change RINGING -> ACTIVE
  793. 2016-08-05 23:56:52.797454 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/masked@1.152.97.29:6517]
  794. 2016-08-05 23:56:52.797454 [NOTICE] switch_ivr.c:779 Channel [sofia/internal/pop@faith.ski] has been answered
  795. 2016-08-05 23:56:52.797454 [DEBUG] switch_channel.c:3770 (sofia/internal/pop@faith.ski) Callstate Change RINGING -> ACTIVE
  796. 2016-08-05 23:56:52.797454 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/masked@1.152.97.29:6517]
  797. 2016-08-05 23:56:52.797454 [DEBUG] switch_ivr_bridge.c:1401 (sofia/internal/pop@faith.ski) State Change CS_EXECUTE -> CS_HIBERNATE
  798. 2016-08-05 23:56:52.797454 [DEBUG] switch_ivr_bridge.c:1402 (sofia/internal/masked@1.152.97.29:6517) State Change CS_CONSUME_MEDIA -> CS_HIBERNATE
  799. 2016-08-05 23:56:52.797454 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/pop@faith.ski) State EXECUTE going to sleep
  800. 2016-08-05 23:56:52.797454 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/pop@faith.ski) Running State Change CS_HIBERNATE
  801. 2016-08-05 23:56:52.797454 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/pop@faith.ski) State HIBERNATE
  802. 2016-08-05 23:56:52.797454 [DEBUG] mod_sofia.c:179 sofia/internal/pop@faith.ski SOFIA HIBERNATE
  803. send 1132 bytes to udp/[49.183.185.185]:23510 at 23:56:52.803585:
  804.    ------------------------------------------------------------------------
  805.    SIP/2.0 200 OK
  806.    Via: SIP/2.0/UDP 49.183.185.185:23510;branch=z9hG4bK-524287-1---0415a7d6262ece37;rport=23510
  807.    From: <sip:pop@faith.ski;transport=UDP>;tag=6be5232a
  808.    To: <sip:masked@faith.ski;transport=UDP>;tag=8Bt584v3Scrjg
  809.    Call-ID: KUzX0zgTmklc6ZVhY5TgKw..
  810.    CSeq: 2 INVITE
  811.    Contact: <sip:masked@45.32.188.45:5060;transport=udp>
  812.    User-Agent: FreeSWITCH
  813.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  814.    Supported: timer, path, replaces
  815.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  816.    Content-Type: application/sdp
  817.    Content-Disposition: session
  818.    Content-Length: 293
  819.    Remote-Party-ID: "masked" <sip:masked@faith.ski>;party=calling;privacy=off;screen=no
  820.    
  821.    v=0
  822.    o=Zoiper 8660380831970978990 1058209101210273600 IN IP4 10.225.191.196
  823.    s=Zoiper
  824.    c=IN IP4 10.225.191.196
  825.    t=0 0
  826.    m=audio 38176 RTP/AVP 3 0 8 9 101
  827.    a=rtpmap:3 GSM/8000
  828.    a=rtpmap:0 PCMU/8000
  829.    a=rtpmap:8 PCMA/8000
  830.    a=rtpmap:9 G722/8000
  831.    a=rtpmap:101 telephone-event/8000
  832.    a=fmtp:101 0-16
  833.    ------------------------------------------------------------------------
  834. 2016-08-05 23:56:52.797454 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/masked@1.152.97.29:6517) Running State Change CS_HIBERNATE
  835. 2016-08-05 23:56:52.797454 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/masked@1.152.97.29:6517) State HIBERNATE
  836. 2016-08-05 23:56:52.797454 [DEBUG] mod_sofia.c:179 sofia/internal/masked@1.152.97.29:6517 SOFIA HIBERNATE
  837. 2016-08-05 23:56:52.797454 [DEBUG] switch_core_state_machine.c:420 sofia/internal/masked@1.152.97.29:6517 Standard HIBERNATE
  838. 2016-08-05 23:56:52.797454 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/masked@1.152.97.29:6517) State HIBERNATE going to sleep
  839. 2016-08-05 23:56:52.797454 [DEBUG] switch_ivr_bridge.c:1211 sofia/internal/pop@faith.ski not hibernating due to active digit parser, semi-hibernation engaged.
  840. 2016-08-05 23:56:52.797454 [DEBUG] sofia.c:6939 Channel sofia/internal/pop@faith.ski entering state [completed][200]
  841. recv 429 bytes from udp/[49.183.185.185]:23510 at 23:56:53.065319:
  842.    ------------------------------------------------------------------------
  843.    ACK sip:masked@45.32.188.45:5060;transport=udp SIP/2.0
  844.    Via: SIP/2.0/UDP 49.183.185.185:23510;branch=z9hG4bK-524287-1---2d559a35d1dbd01d;rport
  845.    Max-Forwards: 70
  846.    Contact: <sip:pop@49.183.185.185:23510;transport=UDP>
  847.    To: <sip:masked@faith.ski;transport=UDP>;tag=8Bt584v3Scrjg
  848.    From: <sip:pop@faith.ski;transport=UDP>;tag=6be5232a
  849.    Call-ID: KUzX0zgTmklc6ZVhY5TgKw..
  850.    CSeq: 2 ACK
  851.    User-Agent: Zoiper r55b5166
  852.    Content-Length: 0
  853.    
  854.    ------------------------------------------------------------------------
  855. 2016-08-05 23:56:53.058100 [DEBUG] sofia.c:6939 Channel sofia/internal/pop@faith.ski entering state [ready][200]
  856. recv 740 bytes from udp/[1.152.97.2