[Nov 7 17:11:11] DEBUG[10969][C-00000837]: res_rtp_asterisk.c:3108 ast_rtcp_read: Got RTCP report of 96 bytes [Nov 7 17:11:11] DEBUG[25482]: chan_sip.c:4417 __sip_autodestruct: Auto destroying SIP dialog '006E415A-DC57-1273-B36F-22A3680AAA77-322368@10.104.163.36' [Nov 7 17:11:11] DEBUG[25482]: chan_sip.c:6822 sip_destroy: Destroying SIP dialog 006E415A-DC57-1273-B36F-22A3680AAA77-322368@10.104.163.36 [Nov 7 17:11:12] DEBUG[25482]: chan_sip.c:4417 __sip_autodestruct: Auto destroying SIP dialog '0001A4A0-DC86-1273-8749-2230B00AAA77-321942@10.176.48.36' [Nov 7 17:11:12] DEBUG[25482]: chan_sip.c:6822 sip_destroy: Destroying SIP dialog 0001A4A0-DC86-1273-8749-2230B00AAA77-321942@10.176.48.36 [Nov 7 17:11:12] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Nov 7 17:11:12] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 7 17:11:12] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 7 17:11:12] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 7 17:11:12] DEBUG[10969][C-00000837]: res_odbc.c:1053 odbc_release_obj2: odbc_release_obj2(0x7f6c480ee368) called (obj->txf = (nil)) [Nov 7 17:11:12] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second -- Playing 'beep.ulaw' (language 'en') [Nov 7 17:11:13] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (182 requested / 182 actual) timer ticks per second [Nov 7 17:11:13] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 7 17:11:13] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 7 17:11:13] DEBUG[10969][C-00000837]: channel.c:3575 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second -- Recording the message [Nov 7 17:11:13] DEBUG[10969][C-00000837]: app.c:1159 __ast_play_and_record: play_and_record: , /var/spool/asterisk/voicemail/GVMA_DN/2344003006/tmp/JeB8Wo, 'wav' [Nov 7 17:11:13] DEBUG[10969][C-00000837]: app.c:1183 __ast_play_and_record: Recording Formats: sfmts=wav -- x=0, open writing: /var/spool/asterisk/voicemail/GVMA_DN/2344003006/tmp/JeB8Wo format: wav, 0x7f6c580db6b8 [Nov 7 17:11:13] DEBUG[10969][C-00000837]: dsp.c:482 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Nov 7 17:11:13] DEBUG[10969][C-00000837]: dsp.c:482 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Nov 7 17:11:13] DEBUG[10969][C-00000837]: channel.c:5359 set_format: Set channel SIP/Asterisk_CLE-00000833 to read format slin [Nov 7 17:11:15] DEBUG[25482]: chan_sip.c:9123 find_call: = Looking for Call ID: 0001A4A0-DC86-1273-8749-2230B00AAA77-321962@10.176.48.36 (Checking From) --From tag 0001A4DC-DC86-1273-8749-2230B00AAA77-322281 --To-tag as40c51490 [Nov 7 17:11:15] DEBUG[25482][C-00000837]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000837] bound to thread. [Nov 7 17:11:15] DEBUG[25482][C-00000837]: chan_sip.c:27891 handle_incoming: **** Received BYE (8) - Command in SIP BYE [Nov 7 17:11:15] DEBUG[25482][C-00000837]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.176.48.36:5060' into... [Nov 7 17:11:15] DEBUG[25482][C-00000837]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.176.48.36' and port '5060'. [Nov 7 17:11:15] DEBUG[25482][C-00000837]: chan_sip.c:3525 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 0001A4A0-DC86-1273-8749-2230B00AAA77-321962@10.176.48.36 [Nov 7 17:11:15] DEBUG[25482][C-00000837]: res_rtp_asterisk.c:3906 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f6c780219c8' [Nov 7 17:11:15] DEBUG[25482][C-00000837]: chan_sip.c:28808 stop_session_timer: Session timer stopped: 135979 - 0001A4A0-DC86-1273-8749-2230B00AAA77-321962@10.176.48.36 [Nov 7 17:11:15] DEBUG[25482][C-00000837]: chan_sip.c:26528 handle_request_bye: Received bye, issuing owner hangup [Nov 7 17:11:15] DEBUG[25482][C-00000837]: chan_sip.c:3869 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.176.48.36:5060 [Nov 7 17:11:15] DEBUG[25482][C-00000837]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000837] being removed from thread. -- User hung up [Nov 7 17:11:15] DEBUG[10969][C-00000837]: channel.c:5359 set_format: Set channel SIP/Asterisk_CLE-00000833 to read format ulaw [Nov 7 17:11:15] DEBUG[10969][C-00000837]: app.c:1746 ast_lock_path_lockfile: Locked path '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX' [Nov 7 17:11:15] DEBUG[10969][C-00000837]: app_voicemail.c:3769 last_message_index: Directory '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX' has no messages and therefore no index was retrieved. [Nov 7 17:11:15] DEBUG[10969][C-00000837]: res_odbc.c:1053 odbc_release_obj2: odbc_release_obj2(0x7f6c480ee368) called (obj->txf = (nil)) [Nov 7 17:11:15] DEBUG[10969][C-00000837]: app.c:1763 ast_unlock_path_lockfile: Unlocked path '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX' [Nov 7 17:11:15] DEBUG[10969][C-00000837]: res_odbc.c:1053 odbc_release_obj2: odbc_release_obj2(0x7f6c480ee368) called (obj->txf = (nil)) [Nov 7 17:11:15] DEBUG[10969][C-00000837]: config.c:1644 config_text_file_load: Parsing /var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt == Parsing '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt': Found [Nov 7 17:11:15] WARNING[10969][C-00000837]: app_voicemail.c:4029 insert_data_cb: SQL Direct Execute failed! [Nov 7 17:11:15] WARNING[10969][C-00000837]: res_odbc.c:608 ast_odbc_direct_execute: SQL Execute error! Verifying connection to Oracle11g [OracleODBC-11g]... [Nov 7 17:11:15] WARNING[10969][C-00000837]: res_odbc.c:761 ast_odbc_sanity_check: Connection is down attempting to reconnect... [Nov 7 17:11:15] DEBUG[10969][C-00000837]: res_odbc.c:1493 odbc_obj_disconnect: Disconnected 0 from Oracle11g [OracleODBC-11g] [Nov 7 17:11:15] DEBUG[10969][C-00000837]: res_odbc.c:1500 odbc_obj_disconnect: Database handle 0x7f6c580e9400 deallocated [Nov 7 17:11:15] NOTICE[10969][C-00000837]: res_odbc.c:1527 odbc_obj_connect: Connecting Oracle11g [Nov 7 17:11:15] NOTICE[10969][C-00000837]: res_odbc.c:1559 odbc_obj_connect: res_odbc: Connected to Oracle11g [OracleODBC-11g] [Nov 7 17:11:16] WARNING[10969][C-00000837]: app_voicemail.c:4029 insert_data_cb: SQL Direct Execute failed! [Nov 7 17:11:16] WARNING[10969][C-00000837]: res_odbc.c:761 ast_odbc_sanity_check: Connection is down attempting to reconnect... [Nov 7 17:11:16] DEBUG[10969][C-00000837]: res_odbc.c:1493 odbc_obj_disconnect: Disconnected 0 from Oracle11g [OracleODBC-11g] [Nov 7 17:11:16] DEBUG[10969][C-00000837]: res_odbc.c:1500 odbc_obj_disconnect: Database handle 0x7f6c580e9400 deallocated [Nov 7 17:11:16] NOTICE[10969][C-00000837]: res_odbc.c:1527 odbc_obj_connect: Connecting Oracle11g [Nov 7 17:11:16] NOTICE[10969][C-00000837]: res_odbc.c:1559 odbc_obj_connect: res_odbc: Connected to Oracle11g [OracleODBC-11g] [Nov 7 17:11:16] WARNING[10969][C-00000837]: app_voicemail.c:4145 store_file: SQL Execute error! [INSERT INTO VOICEMAIL_MSG (dir,msgnum,recording,context,macrocontext,callerid,origtime,duration,mailboxuser,mailboxcontext,flag,msg_id) VALUES (?,?,?,?,?,?,?,?,?,?,?,?)] [Nov 7 17:11:16] DEBUG[10969][C-00000837]: res_odbc.c:1053 odbc_release_obj2: odbc_release_obj2(0x7f6c480ee368) called (obj->txf = (nil)) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: app_voicemail.c:5193 sendmail: Attaching file '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000', format 'wav', uservm is '0', global is 0 [Nov 7 17:11:16] DEBUG[10969][C-00000837]: config.c:1644 config_text_file_load: Parsing /var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt == Parsing '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt': Found [Nov 7 17:11:16] DEBUG[10969][C-00000837]: config.c:1644 config_text_file_load: Parsing /var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt == Parsing '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt': Found [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_MSGNUM' (from 'VM_MSGNUM} in mailbox ${VM_MAILBOX}' len 9) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_MSGNUM' is '1' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_MAILBOX' (from 'VM_MAILBOX}' len 10) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_MAILBOX' is '2344003006' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: config.c:1644 config_text_file_load: Parsing /var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt == Parsing '/var/spool/asterisk/voicemail/GVMA_DN/2344003006/INBOX/msg0000.txt': Found [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_NAME' (from 'VM_NAME}, You have ${VM_MSGNUM} message(s) in mailbox ${VM_Mailbox}. New Message from phone number ${VM_CALLERID} with a duration of ${VM_DUR} on ${VM_DATE}.' len 7) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_NAME' is 'Kevin Shumway' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_MSGNUM' (from 'VM_MSGNUM} message(s) in mailbox ${VM_Mailbox}. New Message from phone number ${VM_CALLERID} with a duration of ${VM_DUR} on ${VM_DATE}.' len 9) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_MSGNUM' is '1' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_Mailbox' (from 'VM_Mailbox}. New Message from phone number ${VM_CALLERID} with a duration of ${VM_DUR} on ${VM_DATE}.' len 10) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_Mailbox' is '2344003006' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_CALLERID' (from 'VM_CALLERID} with a duration of ${VM_DUR} on ${VM_DATE}.' len 11) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_CALLERID' is '"2344003005 - Ullmann, Ivan" <2344003005>' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_DUR' (from 'VM_DUR} on ${VM_DATE}.' len 6) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_DUR' is '0:02' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:4228 ast_str_substitute_variables_full: Evaluating 'VM_DATE' (from 'VM_DATE}.' len 7) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:3642 ast_str_retrieve_variable: Result of 'VM_DATE' is 'Thursday, November 07, 2013 at 03:11:16 PM' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: app_voicemail.c:5204 sendmail: Sent mail to Kevin.Shumway@schwab.com with command '/usr/sbin/sendmail -t' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: res_odbc.c:1053 odbc_release_obj2: odbc_release_obj2(0x7f6c480ee368) called (obj->txf = (nil)) [Nov 7 17:11:16] DEBUG[25468]: chan_sip.c:8726 sip_alloc: Allocating new SIP dialog for 4ea773ec6e478c80752a048659a99367@10.104.163.5:5060 - NOTIFY (No RTP) [Nov 7 17:11:16] DEBUG[25468]: acl.c:979 ast_ouraddrfor: For destination '10.97.13.24', our source address is '10.104.163.5'. [Nov 7 17:11:16] DEBUG[25468]: chan_sip.c:4026 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.104.163.5:5060 [Nov 7 17:11:16] DEBUG[25468]: chan_sip.c:3512 initialize_initreq: Initializing initreq for method NOTIFY - callid 3166dcef5723e002237ee0a3318504a3@10.104.163.5:5060 [Nov 7 17:11:16] DEBUG[25468]: chan_sip.c:3869 __sip_xmit: Trying to put 'NOTIFY sip:' onto UDP socket destined for 10.97.13.24:5060 [Nov 7 17:11:16] DEBUG[10969][C-00000837]: res_odbc.c:1053 odbc_release_obj2: odbc_release_obj2(0x7f6c480ee368) called (obj->txf = (nil)) [Nov 7 17:11:16] DEBUG[10969][C-00000837]: pbx.c:6316 __ast_pbx_run: Spawn extension (sip,2344003006,12) exited non-zero on 'SIP/Asterisk_CLE-00000833' == Spawn extension (sip, 2344003006, 12) exited non-zero on 'SIP/Asterisk_CLE-00000833' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: channel.c:2659 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/Asterisk_CLE-00000833' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: channel.c:2838 ast_hangup: Hanging up channel 'SIP/Asterisk_CLE-00000833' [Nov 7 17:11:16] DEBUG[10969][C-00000837]: chan_sip.c:7054 sip_hangup: Hangup call SIP/Asterisk_CLE-00000833, SIP callid 0001A4A0-DC86-1273-8749-2230B00AAA77-321962@10.176.48.36 [Nov 7 17:11:16] DEBUG[10969][C-00000837]: res_rtp_asterisk.c:3906 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f6c780219c8' [Nov 7 17:11:16] DEBUG[25475]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - Asterisk_CLE [Nov 7 17:11:16] DEBUG[25475]: chan_sip.c:29328 sip_devicestate: Checking device state for peer Asterisk_CLE [Nov 7 17:11:16] DEBUG[25475]: devicestate.c:467 do_state_change: Changing state for SIP/Asterisk_CLE - state 1 (Not in use) [Nov 7 17:11:16] DEBUG[25475]: devicestate.c:442 devstate_event: device 'SIP/Asterisk_CLE' state '1' [Nov 7 17:11:16] DEBUG[25487]: app_queue.c:1804 handle_statechange: Device 'SIP/Asterisk_CLE' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 7 17:11:16] DEBUG[25482]: chan_sip.c:9123 find_call: = Looking for Call ID: 3166dcef5723e002237ee0a3318504a3@10.104.163.5:5060 (Checking To) --From tag as6d4d1bbe --To-tag 1CBFFC90-86B7C447 [Nov 7 17:11:16] DEBUG[25482]: chan_sip.c:4561 __sip_ack: Stopping retransmission on '3166dcef5723e002237ee0a3318504a3@10.104.163.5:5060' of Request 102: Match Found [Nov 7 17:11:16] DEBUG[25482]: chan_sip.c:22882 handle_response_notify: Got 200 accepted on NOTIFY 3166dcef5723e002237ee0a3318504a3@10.104.163.5:5060 [Nov 7 17:11:16] DEBUG[25482]: chan_sip.c:6822 sip_destroy: Destroying SIP dialog 3166dcef5723e002237ee0a3318504a3@10.104.163.5:5060 vvovm1005bdc*CLI> !vi /etc/asterisk/logger.conf [Nov 7 17:11:24] DEBUG[25482]: chan_sip.c:9123 find_call: = Looking for Call ID: 006E415A-DC57-1273-B36F-22A3680AAA77-322395@10.104.163.36 (Checking From) --From tag 006E4178-DC57-1273-B36F-22A3680AAA77-334776 --To-tag [Nov 7 17:11:24] DEBUG[25482]: acl.c:979 ast_ouraddrfor: For destination '10.104.163.36', our source address is '10.104.163.5'. [Nov 7 17:11:24] DEBUG[25482]: chan_sip.c:4026 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.104.163.5:5060 [Nov 7 17:11:24] DEBUG[25482]: chan_sip.c:8726 sip_alloc: Allocating new SIP dialog for 006E415A-DC57-1273-B36F-22A3680AAA77-322395@10.104.163.36 - OPTIONS (No RTP) [Nov 7 17:11:24] DEBUG[25482]: chan_sip.c:27891 handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS [Nov 7 17:11:24] DEBUG[25482]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.104.163.5:5060' into... [Nov 7 17:11:24] DEBUG[25482]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.104.163.5' and port ''. [Nov 7 17:11:24] DEBUG[25482]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.104.163.36:5060' into... [Nov 7 17:11:24] DEBUG[25482]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.104.163.36' and port ''. [Nov 7 17:11:24] DEBUG[25482]: chan_sip.c:3869 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.104.163.36:5060 [Nov 7 17:11:25] DEBUG[25482]: chan_sip.c:9123 find_call: = Looking for Call ID: 0001A4A0-DC86-1273-8749-2230B00AAA77-321973@10.176.48.36 (Checking From) --From tag 0001A4DC-DC86-1273-8749-2230B00AAA77-322292 --To-tag [Nov 7 17:11:25] DEBUG[25482]: acl.c:979 ast_ouraddrfor: For destination '10.176.48.36', our source address is '10.104.163.5'. [Nov 7 17:11:25] DEBUG[25482]: chan_sip.c:4026 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.104.163.5:5060 [Nov 7 17:11:25] DEBUG[25482]: chan_sip.c:8726 sip_alloc: Allocating new SIP dialog for 0001A4A0-DC86-1273-8749-2230B00AAA77-321973@10.176.48.36 - OPTIONS (No RTP) [Nov 7 17:11:25] DEBUG[25482]: chan_sip.c:27891 handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS [Nov 7 17:11:25] DEBUG[25482]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.176.48.5:5060' into... [Nov 7 17:11:25] DEBUG[25482]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.176.48.5' and port ''. [Nov 7 17:11:25] DEBUG[25482]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.176.48.36:5060' into... [Nov 7 17:11:25] DEBUG[25482]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.176.48.36' and port ''. [Nov 7 17:11:25] DEBUG[25482]: chan_sip.c:3869 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.176.48.36:5060 [Nov 7 17:11:26] DEBUG[25482]: chan_sip.c:4417 __sip_autodestruct: Auto destroying SIP dialog '006E415A-DC57-1273-B36F-22A3680AAA77-322377@10.104.163.36' [Nov 7 17:11:26] DEBUG[25482]: chan_sip.c:6822 sip_destroy: Destroying SIP dialog 006E415A-DC57-1273-B36F-22A3680AAA77-322377@10.104.163.36 [Nov 7 17:11:27] DEBUG[25482]: chan_sip.c:4417 __sip_autodestruct: Auto destroying SIP dialog '0001A4A0-DC86-1273-8749-2230B00AAA77-321953@10.176.48.36' [Nov 7 17:11:27] DEBUG[25482]: chan_sip.c:6822 sip_destroy: Destroying SIP dialog 0001A4A0-DC86-1273-8749-2230B00AAA77-321953@10.176.48.36