ASTERISK REMOTE CLI LOG -------------------- -- Executing Answer("SIP/192.168.0.4-08131830", "") in new stack -- Executing MeetMe("SIP/192.168.0.4-08131830", "555|ix") in new stack -- Created MeetMe conference 1023 for conference '555' -- Playing 'conf-getpin' (language 'en') -- Recording -- Playing 'vm-rec-name' (language 'en') -- Playing 'beep' (language 'en') -- x=0, open writing: /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet format: sln, 0x813eb58 -- User ended message by pressing # -- Playing 'auth-thankyou' (language 'en') -- Playing 'vm-review' (language 'en') -- Playing 'vm-msgsaved' (language 'en') -- Playing 'conf-onlyperson' (language 'en') -- Executing Answer("SIP/192.168.0.4-08144f48", "") in new stack -- Executing MeetMe("SIP/192.168.0.4-08144f48", "555|ix") in new stack -- Playing 'conf-getpin' (language 'en') -- Playing 'conf-invalidpin' (language 'en') -- Playing 'conf-getpin' (language 'en') -- Recording -- Playing 'vm-rec-name' (language 'en') -- Playing 'beep' (language 'en') -- x=0, open writing: /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet format: sln, 0x8148890 -- User ended message by pressing # -- Playing 'auth-thankyou' (language 'en') -- Playing 'vm-review' (language 'en') -- Playing 'vm-msgsaved' (language 'en') -- Playing '/opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet' (language 'en') -- Playing 'conf-hasjoin' (language 'en') -- Executing Answer("SIP/192.168.0.4-08155d38", "") in new stack -- Executing MeetMe("SIP/192.168.0.4-08155d38", "555|ix") in new stack -- Playing 'conf-getpin' (language 'en') -- Recording -- Playing 'vm-rec-name' (language 'en') -- Playing 'beep' (language 'en') -- x=0, open writing: /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet format: sln, 0x8158ed8 -- User ended message by pressing # -- Playing 'auth-thankyou' (language 'en') -- Playing 'vm-review' (language 'en') -- Playing 'vm-msgsaved' (language 'en') -- Playing '/opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet' (language 'en') -- Playing 'conf-hasjoin' (language 'en') -- Playing '/opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet' (language 'en') -- Playing 'conf-hasleft' (language 'en') May 24 11:42:04 WARNING[14318]: file.c:509 ast_openstream_full: File /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet does not exist in any format May 24 11:42:04 WARNING[14318]: file.c:821 ast_streamfile: Unable to open /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet (format unknown): No such file or directory -- Playing 'conf-hasleft' (language 'en') -- Hungup 'Zap/pseudo-1489474363' DEBUG/VERBOSE log -------------------- May 24 11:40:41 DEBUG[14292] chan_sip.c: Allocating new SIP dialog for a77b2288-400a8c0-13c4-2da8d-18712fdf-2da8d@192.168.0.4 - INVITE (With RTP) May 24 11:40:41 DEBUG[14292] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE May 24 11:40:41 DEBUG[14292] chan_sip.c: Checking SIP call limits for device May 24 11:40:41 DEBUG[14292] chan_sip.c: Updating call counter for incoming call May 24 11:40:41 DEBUG[14292] chan_sip.c: build_route: Contact hop: May 24 11:40:41 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:40:41 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:40:41 DEBUG[14319] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:40:41 DEBUG[14318] pbx.c: Launching 'Answer' May 24 11:40:41 VERBOSE[14318] logger.c: -- Executing Answer("SIP/192.168.0.4-08131830", "") in new stack May 24 11:40:41 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:40:41 DEBUG[14284] channel.c: Avoiding initial deadlock for 'SIP/192.168.0.4-08131830' May 24 11:40:41 DEBUG[14318] chan_sip.c: sip_answer(SIP/192.168.0.4-08131830) May 24 11:40:41 DEBUG[14318] pbx.c: Launching 'MeetMe' May 24 11:40:41 VERBOSE[14318] logger.c: -- Executing MeetMe("SIP/192.168.0.4-08131830", "555|ix") in new stack May 24 11:40:41 DEBUG[14318] config.c: Parsing /opt/sessionsuite/components/sessionservices/astsupport/etc/asterisk/meetme.conf May 24 11:40:41 DEBUG[14318] config.c: Parsing /opt/sessionsuite/components/sessionservices/astsupport/etc/asterisk/ConferenceRoom555.conf May 24 11:40:41 DEBUG[14318] chan_zap.c: Using channel -2 May 24 11:40:41 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:40:41 DEBUG[14284] devicestate.c: Changing state for Zap/pseudo - state 2 (In use) May 24 11:40:41 VERBOSE[14318] logger.c: -- Created MeetMe conference 1023 for conference '555' May 24 11:40:41 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format gsm May 24 11:40:41 DEBUG[14318] rtp.c: Ooh, format changed from unknown to ulaw May 24 11:40:41 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:40:41 VERBOSE[14318] logger.c: -- Playing 'conf-getpin' (language 'en') May 24 11:40:41 DEBUG[14320] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:40:41 DEBUG[14321] app_queue.c: Device 'Zap/pseudo' changed to state '2' (In use) May 24 11:40:41 DEBUG[14292] chan_sip.c: = Found Their Call ID: a77b2288-400a8c0-13c4-2da8d-18712fdf-2da8d@192.168.0.4 Their Tag a7a222c8-400a8c0-13c4-2da8d-5ad28ef4-2da8d Our tag: as477c2149 May 24 11:40:41 DEBUG[14292] chan_sip.c: **** Received ACK (6) - Command in SIP ACK May 24 11:40:41 DEBUG[14292] chan_sip.c: Stopping retransmission on 'a77b2288-400a8c0-13c4-2da8d-18712fdf-2da8d@192.168.0.4' of Response 1: Match Found May 24 11:40:43 DEBUG[14318] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:40:43 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:43 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format ulaw May 24 11:40:44 DEBUG[14318] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:40:44 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:40:44 DEBUG[14318] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:40:44 DEBUG[14318] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:40:45 DEBUG[14318] rtp.c: Sending dtmf: 35 (#), at 192.168.0.4 May 24 11:40:45 VERBOSE[14318] logger.c: -- Recording May 24 11:40:45 DEBUG[14318] app.c: play_and_record: vm-rec-name, /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet, 'sln' May 24 11:40:45 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format gsm May 24 11:40:45 DEBUG[14318] rtp.c: Difference is 12672, ms is 1604 May 24 11:40:45 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:40:45 VERBOSE[14318] logger.c: -- Playing 'vm-rec-name' (language 'en') May 24 11:40:49 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:49 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:49 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format ulaw May 24 11:40:49 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format gsm May 24 11:40:49 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:40:49 VERBOSE[14318] logger.c: -- Playing 'beep' (language 'en') May 24 11:40:49 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:40:50 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:50 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:50 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format ulaw May 24 11:40:50 DEBUG[14318] app.c: Recording Formats: sfmts=sln May 24 11:40:50 VERBOSE[14318] logger.c: -- x=0, open writing: /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet format: sln, 0x813eb58 May 24 11:40:51 DEBUG[14318] rtp.c: Sending dtmf: 35 (#), at 192.168.0.4 May 24 11:40:51 VERBOSE[14318] logger.c: -- User ended message by pressing # May 24 11:40:51 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format gsm May 24 11:40:51 DEBUG[14318] rtp.c: Difference is 11064, ms is 1403 May 24 11:40:51 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:40:51 VERBOSE[14318] logger.c: -- Playing 'auth-thankyou' (language 'en') May 24 11:40:52 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:52 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:52 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format ulaw May 24 11:40:52 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format gsm May 24 11:40:52 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:40:52 VERBOSE[14318] logger.c: -- Playing 'vm-review' (language 'en') May 24 11:40:52 DEBUG[14318] rtp.c: Sending dtmf: 49 (1), at 192.168.0.4 May 24 11:40:52 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:52 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format ulaw May 24 11:40:52 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format gsm May 24 11:40:52 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:40:52 VERBOSE[14318] logger.c: -- Playing 'vm-msgsaved' (language 'en') May 24 11:40:54 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:40:54 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:54 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:54 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format ulaw May 24 11:40:54 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format gsm May 24 11:40:54 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:40:54 VERBOSE[14318] logger.c: -- Playing 'conf-onlyperson' (language 'en') May 24 11:40:57 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:57 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:40:57 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format ulaw May 24 11:40:57 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to write format slin May 24 11:40:57 DEBUG[14318] channel.c: Set channel SIP/192.168.0.4-08131830 to read format slin May 24 11:40:57 DEBUG[14318] app_meetme.c: Placed channel SIP/192.168.0.4-08131830 in ZAP conf 1023 May 24 11:41:00 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:00 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:04 DEBUG[14292] chan_sip.c: = No match Their Call ID: a77b2288-400a8c0-13c4-2da8d-18712fdf-2da8d@192.168.0.4 Their Tag a7a222c8-400a8c0-13c4-2da8d-5ad28ef4-2da8d Our tag: as477c2149 May 24 11:41:04 DEBUG[14292] chan_sip.c: Allocating new SIP dialog for a77b4188-400a8c0-13c4-2daa3-6e990619-2daa3@192.168.0.4 - INVITE (With RTP) May 24 11:41:04 DEBUG[14292] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE May 24 11:41:04 DEBUG[14292] chan_sip.c: Checking SIP call limits for device May 24 11:41:04 DEBUG[14292] chan_sip.c: Updating call counter for incoming call May 24 11:41:04 DEBUG[14292] chan_sip.c: build_route: Contact hop: May 24 11:41:04 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:41:04 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:41:04 DEBUG[14323] pbx.c: Launching 'Answer' May 24 11:41:04 VERBOSE[14323] logger.c: -- Executing Answer("SIP/192.168.0.4-08144f48", "") in new stack May 24 11:41:04 DEBUG[14323] chan_sip.c: sip_answer(SIP/192.168.0.4-08144f48) May 24 11:41:04 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:41:04 DEBUG[14284] channel.c: Avoiding initial deadlock for 'SIP/192.168.0.4-08144f48' May 24 11:41:04 DEBUG[14324] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:41:04 DEBUG[14323] pbx.c: Launching 'MeetMe' May 24 11:41:04 VERBOSE[14323] logger.c: -- Executing MeetMe("SIP/192.168.0.4-08144f48", "555|ix") in new stack May 24 11:41:04 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:41:04 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:04 DEBUG[14325] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:41:04 DEBUG[14323] rtp.c: Ooh, format changed from unknown to ulaw May 24 11:41:04 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:04 VERBOSE[14323] logger.c: -- Playing 'conf-getpin' (language 'en') May 24 11:41:04 DEBUG[14292] chan_sip.c: = Found Their Call ID: a77b4188-400a8c0-13c4-2daa3-6e990619-2daa3@192.168.0.4 Their Tag a7a22cb8-400a8c0-13c4-2daa3-20a19df6-2daa3 Our tag: as46f52442 May 24 11:41:04 DEBUG[14292] chan_sip.c: **** Received ACK (6) - Command in SIP ACK May 24 11:41:04 DEBUG[14292] chan_sip.c: Stopping retransmission on 'a77b4188-400a8c0-13c4-2daa3-6e990619-2daa3@192.168.0.4' of Response 1: Match Found May 24 11:41:06 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:06 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:06 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:06 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:06 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:06 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:08 DEBUG[14323] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:08 DEBUG[14323] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:08 DEBUG[14323] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:10 DEBUG[14323] rtp.c: Sending dtmf: 35 (#), at 192.168.0.4 May 24 11:41:10 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:10 DEBUG[14323] rtp.c: Difference is 31232, ms is 3924 May 24 11:41:10 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:10 VERBOSE[14323] logger.c: -- Playing 'conf-invalidpin' (language 'en') May 24 11:41:11 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:11 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:12 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:13 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:13 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:13 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:13 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:13 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:13 VERBOSE[14323] logger.c: -- Playing 'conf-getpin' (language 'en') May 24 11:41:15 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:15 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:15 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:16 DEBUG[14323] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:16 DEBUG[14323] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:16 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:16 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:16 DEBUG[14323] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:17 DEBUG[14323] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:17 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:17 DEBUG[14323] rtp.c: Sending dtmf: 35 (#), at 192.168.0.4 May 24 11:41:17 VERBOSE[14323] logger.c: -- Recording May 24 11:41:17 DEBUG[14323] app.c: play_and_record: vm-rec-name, /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet, 'sln' May 24 11:41:17 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:17 DEBUG[14323] rtp.c: Difference is 12480, ms is 1580 May 24 11:41:17 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:17 VERBOSE[14323] logger.c: -- Playing 'vm-rec-name' (language 'en') May 24 11:41:21 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:21 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:21 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:21 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:21 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:21 VERBOSE[14323] logger.c: -- Playing 'beep' (language 'en') May 24 11:41:21 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:21 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:22 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:22 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:22 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:22 DEBUG[14323] app.c: Recording Formats: sfmts=sln May 24 11:41:22 VERBOSE[14323] logger.c: -- x=0, open writing: /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet format: sln, 0x8148890 May 24 11:41:23 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:23 DEBUG[14323] rtp.c: Sending dtmf: 35 (#), at 192.168.0.4 May 24 11:41:23 VERBOSE[14323] logger.c: -- User ended message by pressing # May 24 11:41:23 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:23 DEBUG[14323] rtp.c: Difference is 15032, ms is 1899 May 24 11:41:23 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:23 VERBOSE[14323] logger.c: -- Playing 'auth-thankyou' (language 'en') May 24 11:41:24 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:24 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:24 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:24 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:24 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:24 VERBOSE[14323] logger.c: -- Playing 'vm-review' (language 'en') May 24 11:41:25 DEBUG[14323] rtp.c: Sending dtmf: 49 (1), at 192.168.0.4 May 24 11:41:25 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:25 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:25 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format gsm May 24 11:41:25 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:25 VERBOSE[14323] logger.c: -- Playing 'vm-msgsaved' (language 'en') May 24 11:41:27 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:27 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:27 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format ulaw May 24 11:41:27 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to write format slin May 24 11:41:27 DEBUG[14323] channel.c: Set channel SIP/192.168.0.4-08144f48 to read format slin May 24 11:41:27 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format slin May 24 11:41:27 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:27 VERBOSE[14323] logger.c: -- Playing '/opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet' (language 'en') May 24 11:41:27 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:27 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:28 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:28 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:28 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format ulaw May 24 11:41:28 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format gsm May 24 11:41:28 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:28 VERBOSE[14323] logger.c: -- Playing 'conf-hasjoin' (language 'en') May 24 11:41:30 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:30 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:30 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format ulaw May 24 11:41:30 DEBUG[14323] app_meetme.c: Placed channel SIP/192.168.0.4-08144f48 in ZAP conf 1023 May 24 11:41:30 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:30 DEBUG[14323] rtp.c: Difference is 27272, ms is 3429 May 24 11:41:31 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:31 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:31 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:31 DEBUG[14323] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08144f48, f->frametype=5,f->subclass=0 May 24 11:41:37 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:37 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:37 DEBUG[14292] chan_sip.c: = No match Their Call ID: a77b4188-400a8c0-13c4-2daa3-6e990619-2daa3@192.168.0.4 Their Tag a7a22cb8-400a8c0-13c4-2daa3-20a19df6-2daa3 Our tag: as46f52442 May 24 11:41:37 DEBUG[14292] chan_sip.c: = No match Their Call ID: a77b2288-400a8c0-13c4-2da8d-18712fdf-2da8d@192.168.0.4 Their Tag a7a222c8-400a8c0-13c4-2da8d-5ad28ef4-2da8d Our tag: as477c2149 May 24 11:41:37 DEBUG[14292] chan_sip.c: Allocating new SIP dialog for a77b6088-400a8c0-13c4-2dac4-10a47c33-2dac4@192.168.0.4 - INVITE (With RTP) May 24 11:41:37 DEBUG[14292] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE May 24 11:41:37 DEBUG[14292] chan_sip.c: Checking SIP call limits for device May 24 11:41:37 DEBUG[14292] chan_sip.c: Updating call counter for incoming call May 24 11:41:37 DEBUG[14292] chan_sip.c: build_route: Contact hop: May 24 11:41:37 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:41:37 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:41:37 DEBUG[14328] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:41:37 DEBUG[14327] pbx.c: Launching 'Answer' May 24 11:41:37 VERBOSE[14327] logger.c: -- Executing Answer("SIP/192.168.0.4-08155d38", "") in new stack May 24 11:41:37 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:41:37 DEBUG[14284] channel.c: Avoiding initial deadlock for 'SIP/192.168.0.4-08155d38' May 24 11:41:37 DEBUG[14327] chan_sip.c: sip_answer(SIP/192.168.0.4-08155d38) May 24 11:41:37 DEBUG[14327] pbx.c: Launching 'MeetMe' May 24 11:41:37 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:41:37 DEBUG[14329] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:41:37 VERBOSE[14327] logger.c: -- Executing MeetMe("SIP/192.168.0.4-08155d38", "555|ix") in new stack May 24 11:41:37 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format gsm May 24 11:41:37 DEBUG[14327] rtp.c: Ooh, format changed from unknown to ulaw May 24 11:41:37 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:37 VERBOSE[14327] logger.c: -- Playing 'conf-getpin' (language 'en') May 24 11:41:37 DEBUG[14292] chan_sip.c: = Found Their Call ID: a77b6088-400a8c0-13c4-2dac4-10a47c33-2dac4@192.168.0.4 Their Tag a7a236a8-400a8c0-13c4-2dac4-48293658-2dac4 Our tag: as706adebe May 24 11:41:37 DEBUG[14292] chan_sip.c: **** Received ACK (6) - Command in SIP ACK May 24 11:41:37 DEBUG[14292] chan_sip.c: Stopping retransmission on 'a77b6088-400a8c0-13c4-2dac4-10a47c33-2dac4@192.168.0.4' of Response 1: Match Found May 24 11:41:37 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:37 DEBUG[14323] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08144f48, f->frametype=5,f->subclass=0 May 24 11:41:39 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:39 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:39 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format ulaw May 24 11:41:39 DEBUG[14327] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:39 DEBUG[14327] rtp.c: Got RTCP report of 72 bytes May 24 11:41:40 DEBUG[14327] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:40 DEBUG[14327] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:40 DEBUG[14327] rtp.c: Sending dtmf: 53 (5), at 192.168.0.4 May 24 11:41:41 DEBUG[14327] rtp.c: Sending dtmf: 35 (#), at 192.168.0.4 May 24 11:41:41 VERBOSE[14327] logger.c: -- Recording May 24 11:41:41 DEBUG[14327] app.c: play_and_record: vm-rec-name, /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet, 'sln' May 24 11:41:41 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format gsm May 24 11:41:41 DEBUG[14327] rtp.c: Difference is 14296, ms is 1807 May 24 11:41:41 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:41 VERBOSE[14327] logger.c: -- Playing 'vm-rec-name' (language 'en') May 24 11:41:41 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:41 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:41 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:41 DEBUG[14323] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08144f48, f->frametype=5,f->subclass=0 May 24 11:41:45 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:45 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:45 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format ulaw May 24 11:41:45 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format gsm May 24 11:41:45 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:45 VERBOSE[14327] logger.c: -- Playing 'beep' (language 'en') May 24 11:41:45 DEBUG[14327] rtp.c: Got RTCP report of 72 bytes May 24 11:41:46 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:46 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:46 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format ulaw May 24 11:41:46 DEBUG[14327] app.c: Recording Formats: sfmts=sln May 24 11:41:46 VERBOSE[14327] logger.c: -- x=0, open writing: /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet format: sln, 0x8158ed8 May 24 11:41:46 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:46 DEBUG[14323] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08144f48, f->frametype=5,f->subclass=0 May 24 11:41:47 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:47 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:48 DEBUG[14327] rtp.c: Sending dtmf: 35 (#), at 192.168.0.4 May 24 11:41:48 VERBOSE[14327] logger.c: -- User ended message by pressing # May 24 11:41:48 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format gsm May 24 11:41:48 DEBUG[14327] rtp.c: Difference is 15824, ms is 1998 May 24 11:41:48 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:48 VERBOSE[14327] logger.c: -- Playing 'auth-thankyou' (language 'en') May 24 11:41:48 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:48 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:48 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format ulaw May 24 11:41:48 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format gsm May 24 11:41:48 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:48 VERBOSE[14327] logger.c: -- Playing 'vm-review' (language 'en') May 24 11:41:49 DEBUG[14327] rtp.c: Sending dtmf: 49 (1), at 192.168.0.4 May 24 11:41:49 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:49 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format ulaw May 24 11:41:49 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format gsm May 24 11:41:49 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:49 VERBOSE[14327] logger.c: -- Playing 'vm-msgsaved' (language 'en') May 24 11:41:51 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:51 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:51 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format ulaw May 24 11:41:51 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to write format slin May 24 11:41:51 DEBUG[14327] channel.c: Set channel SIP/192.168.0.4-08155d38 to read format slin May 24 11:41:51 DEBUG[14327] channel.c: Set channel Zap/pseudo-1489474363 to write format slin May 24 11:41:51 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:51 VERBOSE[14327] logger.c: -- Playing '/opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet' (language 'en') May 24 11:41:51 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:51 DEBUG[14323] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08144f48, f->frametype=5,f->subclass=0 May 24 11:41:52 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:52 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:52 DEBUG[14327] channel.c: Set channel Zap/pseudo-1489474363 to write format ulaw May 24 11:41:52 DEBUG[14327] channel.c: Set channel Zap/pseudo-1489474363 to write format gsm May 24 11:41:52 DEBUG[14327] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:52 VERBOSE[14327] logger.c: -- Playing 'conf-hasjoin' (language 'en') May 24 11:41:53 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:53 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:41:54 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:54 DEBUG[14327] channel.c: Scheduling timer at 0 sample intervals May 24 11:41:54 DEBUG[14327] channel.c: Set channel Zap/pseudo-1489474363 to write format ulaw May 24 11:41:54 DEBUG[14327] app_meetme.c: Placed channel SIP/192.168.0.4-08155d38 in ZAP conf 1023 May 24 11:41:54 DEBUG[14327] rtp.c: Got RTCP report of 72 bytes May 24 11:41:54 DEBUG[14327] rtp.c: Difference is 27560, ms is 3465 May 24 11:41:54 DEBUG[14327] rtp.c: Got RTCP report of 72 bytes May 24 11:41:54 DEBUG[14327] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08155d38, f->frametype=5,f->subclass=0 May 24 11:41:55 DEBUG[14323] rtp.c: Got RTCP report of 72 bytes May 24 11:41:55 DEBUG[14323] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08144f48, f->frametype=5,f->subclass=0 May 24 11:41:58 DEBUG[14292] chan_sip.c: = No match Their Call ID: a77b6088-400a8c0-13c4-2dac4-10a47c33-2dac4@192.168.0.4 Their Tag a7a236a8-400a8c0-13c4-2dac4-48293658-2dac4 Our tag: as706adebe May 24 11:41:58 DEBUG[14292] chan_sip.c: = Found Their Call ID: a77b4188-400a8c0-13c4-2daa3-6e990619-2daa3@192.168.0.4 Their Tag a7a22cb8-400a8c0-13c4-2daa3-20a19df6-2daa3 Our tag: as46f52442 May 24 11:41:58 DEBUG[14292] chan_sip.c: **** Received BYE (8) - Command in SIP BYE May 24 11:41:58 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format slin May 24 11:41:58 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:41:58 VERBOSE[14323] logger.c: -- Playing '/opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet' (language 'en') May 24 11:41:59 DEBUG[14318] rtp.c: Got RTCP report of 72 bytes May 24 11:41:59 DEBUG[14318] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08131830, f->frametype=5,f->subclass=0 May 24 11:42:00 DEBUG[14327] rtp.c: Got RTCP report of 72 bytes May 24 11:42:00 DEBUG[14327] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08155d38, f->frametype=5,f->subclass=0 May 24 11:42:00 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:42:00 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:42:00 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format ulaw May 24 11:42:00 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format gsm May 24 11:42:00 DEBUG[14323] channel.c: Scheduling timer at 160 sample intervals May 24 11:42:00 VERBOSE[14323] logger.c: -- Playing 'conf-hasleft' (language 'en') May 24 11:42:02 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:42:02 DEBUG[14323] channel.c: Scheduling timer at 0 sample intervals May 24 11:42:02 DEBUG[14323] channel.c: Set channel Zap/pseudo-1489474363 to write format ulaw May 24 11:42:02 DEBUG[14323] pbx.c: Spawn extension (incoming,5555,2) exited non-zero on 'SIP/192.168.0.4-08144f48' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '"1111 Res3" <1111>' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '1111' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '5555' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is 'incoming' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is 'SIP/192.168.0.4-08144f48' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '(null)' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is 'MeetMe' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '555|ix' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '2006-05-24 11:41:04' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '2006-05-24 11:41:04' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '2006-05-24 11:42:02' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '58' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '58' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is 'ANSWERED' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is 'DOCUMENTATION' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '(null)' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '1148485264.4' May 24 11:42:02 DEBUG[14323] pbx.c: Function result is '(null)' May 24 11:42:02 DEBUG[14323] channel.c: Hanging up channel 'SIP/192.168.0.4-08144f48' May 24 11:42:02 DEBUG[14323] chan_sip.c: Hangup call SIP/192.168.0.4-08144f48, SIP callid a77b4188-400a8c0-13c4-2daa3-6e990619-2daa3@192.168.0.4) May 24 11:42:02 DEBUG[14323] chan_sip.c: update_call_counter() - decrement call limit counter May 24 11:42:02 DEBUG[14323] chan_sip.c: Updating call counter for incoming call May 24 11:42:02 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:42:02 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:42:02 DEBUG[14331] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:42:04 DEBUG[14292] chan_sip.c: = No match Their Call ID: a77b6088-400a8c0-13c4-2dac4-10a47c33-2dac4@192.168.0.4 Their Tag a7a236a8-400a8c0-13c4-2dac4-48293658-2dac4 Our tag: as706adebe May 24 11:42:04 DEBUG[14292] chan_sip.c: = Found Their Call ID: a77b2288-400a8c0-13c4-2da8d-18712fdf-2da8d@192.168.0.4 Their Tag a7a222c8-400a8c0-13c4-2da8d-5ad28ef4-2da8d Our tag: as477c2149 May 24 11:42:04 DEBUG[14292] chan_sip.c: **** Received BYE (8) - Command in SIP BYE May 24 11:42:04 WARNING[14318] file.c: File /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet does not exist in any format May 24 11:42:04 WARNING[14318] file.c: Unable to open /opt/sessionsuite/components/sessionservices/astsupport/var/spool/asterisk/meet (format unknown): No such file or directory May 24 11:42:04 DEBUG[14318] channel.c: Set channel Zap/pseudo-1489474363 to write format gsm May 24 11:42:04 DEBUG[14318] channel.c: Scheduling timer at 160 sample intervals May 24 11:42:04 VERBOSE[14318] logger.c: -- Playing 'conf-hasleft' (language 'en') May 24 11:42:05 DEBUG[14327] rtp.c: Got RTCP report of 72 bytes May 24 11:42:05 DEBUG[14327] app_meetme.c: Got unrecognized frame on channel SIP/192.168.0.4-08155d38, f->frametype=5,f->subclass=0 May 24 11:42:05 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:42:05 DEBUG[14318] channel.c: Scheduling timer at 0 sample intervals May 24 11:42:05 DEBUG[14318] channel.c: Set channel Zap/pseudo-1489474363 to write format ulaw May 24 11:42:05 DEBUG[14318] pbx.c: Spawn extension (incoming,5555,2) exited non-zero on 'SIP/192.168.0.4-08131830' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '"1100 Res3" <1100>' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '1100' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '5555' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is 'incoming' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is 'SIP/192.168.0.4-08131830' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '(null)' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is 'MeetMe' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '555|ix' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '2006-05-24 11:40:41' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '2006-05-24 11:40:41' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '2006-05-24 11:42:05' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '84' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '84' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is 'ANSWERED' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is 'DOCUMENTATION' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '(null)' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '1148485241.2' May 24 11:42:05 DEBUG[14318] pbx.c: Function result is '(null)' May 24 11:42:05 DEBUG[14318] channel.c: Hanging up channel 'SIP/192.168.0.4-08131830' May 24 11:42:05 DEBUG[14318] chan_sip.c: Hangup call SIP/192.168.0.4-08131830, SIP callid a77b2288-400a8c0-13c4-2da8d-18712fdf-2da8d@192.168.0.4) May 24 11:42:05 DEBUG[14318] chan_sip.c: update_call_counter() - decrement call limit counter May 24 11:42:05 DEBUG[14318] chan_sip.c: Updating call counter for incoming call May 24 11:42:05 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:42:05 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 2 (In use) May 24 11:42:05 DEBUG[14332] app_queue.c: Device 'SIP/192.168.0.4' changed to state '2' (In use) May 24 11:42:08 DEBUG[14292] chan_sip.c: = Found Their Call ID: a77b6088-400a8c0-13c4-2dac4-10a47c33-2dac4@192.168.0.4 Their Tag a7a236a8-400a8c0-13c4-2dac4-48293658-2dac4 Our tag: as706adebe May 24 11:42:08 DEBUG[14292] chan_sip.c: **** Received BYE (8) - Command in SIP BYE May 24 11:42:08 DEBUG[14327] channel.c: Hanging up channel 'Zap/pseudo-1489474363' May 24 11:42:08 DEBUG[14327] chan_zap.c: zt_hangup(Zap/pseudo-1489474363) May 24 11:42:08 DEBUG[14327] chan_zap.c: Hangup: channel: -2 index = 0, normal = 30, callwait = -1, thirdcall = -1 May 24 11:42:08 DEBUG[14327] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/pseudo-1489474363 May 24 11:42:08 DEBUG[14327] chan_zap.c: Updated conferencing on -2, with 0 conference users May 24 11:42:08 VERBOSE[14327] logger.c: -- Hungup 'Zap/pseudo-1489474363' May 24 11:42:08 DEBUG[14327] pbx.c: Spawn extension (incoming,5555,2) exited non-zero on 'SIP/192.168.0.4-08155d38' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '"1122 Res3" <1122>' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '1122' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '5555' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is 'incoming' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is 'SIP/192.168.0.4-08155d38' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '(null)' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is 'MeetMe' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '555|ix' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '2006-05-24 11:41:37' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '2006-05-24 11:41:37' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '2006-05-24 11:42:08' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '31' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '31' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is 'ANSWERED' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is 'DOCUMENTATION' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '(null)' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '1148485297.5' May 24 11:42:08 DEBUG[14327] pbx.c: Function result is '(null)' May 24 11:42:08 DEBUG[14327] channel.c: Hanging up channel 'SIP/192.168.0.4-08155d38' May 24 11:42:08 DEBUG[14327] chan_sip.c: Hangup call SIP/192.168.0.4-08155d38, SIP callid a77b6088-400a8c0-13c4-2dac4-10a47c33-2dac4@192.168.0.4) May 24 11:42:08 DEBUG[14327] chan_sip.c: update_call_counter() - decrement call limit counter May 24 11:42:08 DEBUG[14327] chan_sip.c: Updating call counter for incoming call May 24 11:42:08 DEBUG[14284] devicestate.c: Changing state for Zap/pseudo - state 0 (Unknown) May 24 11:42:08 DEBUG[14284] chan_sip.c: Checking device state for peer 192.168.0.4 May 24 11:42:08 DEBUG[14284] devicestate.c: Changing state for SIP/192.168.0.4 - state 1 (Not in use) May 24 11:42:08 DEBUG[14333] app_queue.c: Device 'Zap/pseudo' changed to state '0' (Unknown) May 24 11:42:08 DEBUG[14334] app_queue.c: Device 'SIP/192.168.0.4' changed to state '1' (Not in use)