[Oct 8 11:28:23] Asterisk SVN-branch-12-r400671 built by root @ on a i686 running Linux on 2013-10-01 16:12:22 UTC [Oct 8 11:28:23] VERBOSE[13105] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Oct 8 11:28:23] VERBOSE[13105] logger.c: Asterisk Queue Logger restarted [Oct 8 11:28:25] VERBOSE[13040] res_pjsip_registrar.c: -- Added contact 'sip:phone_A@10.24.19.97:5060;ob' to AOR 'phone_A' with expiration of 300 seconds [Oct 8 11:28:25] WARNING[13040] res_pjsip_pubsub.c: Subscriptions not permitted for endpoint phone_A. [Oct 8 11:28:25] WARNING[13040] res_pjsip_pubsub.c: Subscriptions not permitted for endpoint phone_A. [Oct 8 11:28:29] Asterisk SVN-branch-12-r400671 built by root @ putang2 on a i686 running Linux on 2013-10-01 16:12:22 UTC [Oct 8 11:28:29] DEBUG[13105] config.c: Parsing /etc/asterisk/logger.conf [Oct 8 11:28:29] VERBOSE[13105] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Oct 8 11:28:29] VERBOSE[13105] logger.c: Asterisk Queue Logger restarted [Oct 8 11:28:36] VERBOSE[13040] res_pjsip_registrar.c: -- Added contact 'sip:phone_B@10.24.18.165:5060;ob' to AOR 'phone_B' with expiration of 300 seconds [Oct 8 11:28:36] DEBUG[13026] devicestate.c: Processing device state change for 'PJSIP/phone_B' [Oct 8 11:28:36] DEBUG[13026] devicestate.c: Adding per-server state of 'Not in use' for 'PJSIP/phone_B' [Oct 8 11:28:36] DEBUG[13026] devicestate.c: Aggregate devstate result is 'Not in use' for 'PJSIP/phone_B' [Oct 8 11:28:36] DEBUG[13026] devicestate.c: Aggregate state for device 'PJSIP/phone_B' has changed to 'Not in use' [Oct 8 11:28:36] WARNING[13040] res_pjsip_pubsub.c: Subscriptions not permitted for endpoint phone_B. [Oct 8 11:28:36] WARNING[13040] res_pjsip_pubsub.c: Subscriptions not permitted for endpoint phone_B. [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xa4d1fe4' [Oct 8 11:28:40] DEBUG[13040] res_rtp_asterisk.c: Allocated port 10068 for RTP instance '0xa4d1fe4' [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: RTP instance '0xa4d1fe4' is setup and ready to go [Oct 8 11:28:40] DEBUG[13040] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xa4d1fe4' [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 0 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 8 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 9 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 111 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 18 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 58 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 118 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 58 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 96 based on m type on 0xb5c88548 [Oct 8 11:28:40] DEBUG[13168][C-00000000] pbx.c: Launching 'Answer' [Oct 8 11:28:40] VERBOSE[13168][C-00000000] pbx.c: -- Executing [999@internal:1] Answer("PJSIP/phone_A-00000000", "") in new stack [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Processing device state change for 'PJSIP/phone_A' [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Adding per-server state of 'In use' for 'PJSIP/phone_A' [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Aggregate devstate result is 'In use' for 'PJSIP/phone_A' [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Aggregate state for device 'PJSIP/phone_A' has changed to 'In use' [Oct 8 11:28:40] DEBUG[13040] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa4d1fe4' [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 0 based on m type on 0xb5c87fd8 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 8 based on m type on 0xb5c87fd8 [Oct 8 11:28:40] DEBUG[13040] rtp_engine.c: Setting payload 96 based on m type on 0xb5c87fd8 [Oct 8 11:28:40] DEBUG[13168][C-00000000] res_rtp_asterisk.c: 0xa482e10 -- Probation learning mode pass with source address 10.24.19.97:4010 [Oct 8 11:28:40] VERBOSE[13168][C-00000000] pbx.c: -- Auto fallthrough, channel 'PJSIP/phone_A-00000000' status is 'UNKNOWN' [Oct 8 11:28:40] DEBUG[13168][C-00000000] channel.c: Soft-Hanging up channel 'PJSIP/phone_A-00000000' [Oct 8 11:28:40] DEBUG[13168][C-00000000] channel.c: Hanging up channel 'PJSIP/phone_A-00000000' [Oct 8 11:28:40] DEBUG[13168][C-00000000] chan_pjsip.c: AST hangup cause 0 (no match found in PJSIP) [Oct 8 11:28:40] DEBUG[13030] cdr.c: Finalized CDR for PJSIP/phone_A-00000000 - start 1381249720.348572 answer 1381249720.348966 end 1381249720.575135 dispo ANSWERED [Oct 8 11:28:40] DEBUG[13030] cdr_radius.c: Unable to create RADIUS record. CDR not recorded! [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Processing device state change for 'PJSIP/phone_A' [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Adding per-server state of 'Not in use' for 'PJSIP/phone_A' [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Aggregate devstate result is 'Not in use' for 'PJSIP/phone_A' [Oct 8 11:28:40] DEBUG[13026] devicestate.c: Aggregate state for device 'PJSIP/phone_A' has changed to 'Not in use' [Oct 8 11:28:40] DEBUG[13030] res_config_sqlite.c: About to query table structure: SELECT sql FROM sqlite_master WHERE type='table' AND tbl_name='ast_cdr' [Oct 8 11:28:40] DEBUG[13030] res_config_sqlite.c: SQL query: INSERT INTO ast_cdr (clid,src,dst,dcontext,channel,lastapp,start,answer,end,duration,billsec,disposition,amaflags,uniqueid) VALUES ('"Phone A" <1001>','1001','999','internal','PJSIP/phone_A-00000000','Answer','2013-10-08 11:28:40','2013-10-08 11:28:40','2013-10-08 11:28:40','0','0','ANSWERED','DOCUMENTATION','1381249720.0') [Oct 8 11:28:40] ERROR[13040] astobj2.c: user_data is NULL [Oct 8 11:28:40] ERROR[13040] astobj2.c: FRACK!, Failed assertion 0 (0)