[Dec  3 18:31:56] DEBUG[188844]: res_pjsip/pjsip_distributor.c:267 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=102 (rdata0x19dc848)
[Dec  3 18:31:56] DEBUG[188844]: res_pjsip/pjsip_distributor.c:359 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000030 to use for Request msg INVITE/cseq=102 (rdata0x19dc848)
[Dec  3 18:31:56] DEBUG[188823]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'X.X.X.X' into...
[Dec  3 18:31:56] DEBUG[188823]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'X.X.X.X' and port ''.
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address X.X.X.X:5060 does not match identify '47.201.54.253'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address X.X.X.X:5060 does not match identify 'music'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address X.X.X.X:5060 does not match identify '172.16.7.109'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_endpoint_identifier_ip.c:113 ip_identify_match_check: Source address X.X.X.X:5060 does not match identify '192.168.1.8'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_endpoint_identifier_ip.c:108 ip_identify_match_check: Source address X.X.X.X:5060 matches identify 'X.X.X.X'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_endpoint_identifier_ip.c:143 ip_identify: Retrieved endpoint system-ulawg729
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip/pjsip_distributor.c:359 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000030 to use for Request msg INVITE/cseq=102 (rdata0x7fcfb0001338)
[Dec  3 18:31:56] DEBUG[188823]: pbx.c:1268 new_find_extension: return because scoreboard has a match with '/'--- _X.
[Dec  3 18:31:56] DEBUG[188823]: pbx.c:1254 new_find_extension: returning an exact match-- _X.
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:269 handle_incoming_sdp: Negotiating incoming SDP media stream 'audio' using audio SDP handler
[Dec  3 18:31:56] DEBUG[188823]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'X.X.X.X' into...
[Dec  3 18:31:56] DEBUG[188823]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'X.X.X.X' and port ''.
[Dec  3 18:31:56] DEBUG[188823]: rtp_engine.c:454 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fd0080046e0'
[Dec  3 18:31:56] WARNING[188823]: res_rtp_asterisk.c:2400 create_new_socket: Unable to allocate RTP socket: Address family not supported by protocol
[Dec  3 18:31:56] WARNING[188823]: res_rtp_asterisk.c:2665 ast_rtp_new: Failed to create a new socket for RTP instance '0x7fd0080046e0'
[Dec  3 18:31:56] DEBUG[188823]: rtp_engine.c:458 ast_rtp_instance_new: Engine 'asterisk' failed to setup RTP instance '0x7fd0080046e0'
[Dec  3 18:31:56] DEBUG[188823]: rtp_engine.c:397 instance_destructor: Destroyed RTP instance '0x7fd0080046e0'
[Dec  3 18:31:56] ERROR[188823]: res_pjsip_sdp_rtp.c:184 create_rtp: Unable to create RTP instance using RTP engine 'asterisk'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2494 handle_outgoing_response: Method is INVITE, Response is 488 Not Acceptable Here
[Dec  3 18:31:56] DEBUG[188823]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'X.X.X.X' into...
[Dec  3 18:31:56] DEBUG[188823]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'X.X.X.X' and port ''.
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2384 __print_debug_details: Function session_inv_on_state_changed called on event TSX_STATE
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2398 __print_debug_details: The state change pertains to the endpoint 'system-ulawg729()'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2403 __print_debug_details: The inv session still has an invite_tsx (0x7fd0080054c8)
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2418 __print_debug_details: There is no transaction involved in this state change
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2420 __print_debug_details: The current inv state is DISCONNCTD
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2595 session_inv_on_state_changed: Source of transaction state change is TX_MSG
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2384 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2398 __print_debug_details: The state change pertains to the endpoint 'system-ulawg729()'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2403 __print_debug_details: The inv session still has an invite_tsx (0x7fd0080054c8)
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2409 __print_debug_details: The UAS INVITE transaction involved in this state change is 0x7fd0080054c8
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2413 __print_debug_details: The current transaction state is Completed
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2415 __print_debug_details: The transaction state change event is TX_MSG
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2420 __print_debug_details: The current inv state is DISCONNCTD
[Dec  3 18:31:56] DEBUG[188844]: res_pjsip/pjsip_distributor.c:390 distributor: Searching for serializer on dialog dlg0x7fd008001ec8 for Request msg ACK/cseq=102 (rdata0x7fcfb0003288)
[Dec  3 18:31:56] DEBUG[188844]: res_pjsip/pjsip_distributor.c:396 distributor: Found serializer pjsip/distributor-00000030 on dialog dlg0x7fd008001ec8
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2384 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2398 __print_debug_details: The state change pertains to the endpoint 'system-ulawg729()'
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2403 __print_debug_details: The inv session still has an invite_tsx (0x7fd0080054c8)
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2409 __print_debug_details: The UAS INVITE transaction involved in this state change is 0x7fd0080054c8
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2413 __print_debug_details: The current transaction state is Confirmed
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2415 __print_debug_details: The transaction state change event is RX_MSG
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2420 __print_debug_details: The current inv state is DISCONNCTD
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2463 handle_incoming: Received request
[Dec  3 18:31:56] DEBUG[188823]: res_pjsip_session.c:2430 handle_incoming_request: Method is ACK
[Dec  3 18:32:01] DEBUG[188860]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1480789921  Interval: 30
[Dec  3 18:32:01] DEBUG[188860]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts
[Dec  3 18:32:01] DEBUG[188844]: res_pjsip_session.c:2384 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Dec  3 18:32:01] DEBUG[188844]: res_pjsip_session.c:2398 __print_debug_details: The state change pertains to the endpoint 'system-ulawg729()'
[Dec  3 18:32:01] DEBUG[188844]: res_pjsip_session.c:2406 __print_debug_details: The inv session does NOT have an invite_tsx
[Dec  3 18:32:01] DEBUG[188844]: res_pjsip_session.c:2409 __print_debug_details: The UAS INVITE transaction involved in this state change is 0x7fd0080054c8
[Dec  3 18:32:01] DEBUG[188844]: res_pjsip_session.c:2413 __print_debug_details: The current transaction state is Terminated
[Dec  3 18:32:01] DEBUG[188844]: res_pjsip_session.c:2415 __print_debug_details: The transaction state change event is TIMER
[Dec  3 18:32:01] DEBUG[188844]: res_pjsip_session.c:2420 __print_debug_details: The current inv state is DISCONNCTD
[Dec  3 18:32:01] DEBUG[188823]: res_pjsip_session.c:1322 session_destructor: Destroying SIP session with endpoint system-ulawg729