[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:8088 find_call: = Looking for  Call ID: 4989f87ac39d498882ba90e86679be04 (Checking From) --From tag b74822e52cbb45a99492d985fa0e0432 --To-tag
[Mar 12 18:20:25] DEBUG[7868]: acl.c:728 ast_ouraddrfor: For destination '10.1.50.254', our source address is '10.1.52.57'.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:7768 sip_alloc: Allocating new SIP dialog for 4989f87ac39d498882ba90e86679be04 - REGISTER (No RTP)
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:25049 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.86.0.50:61363' into...
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.86.0.50' and port '61363'.
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.1.52.57' into...
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.1.52.57' and port ''.
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:702 append_var_and_value_to_filter: name='name' value='14484442'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:702 append_var_and_value_to_filter: name='host' value='dynamic'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: sn LDAP value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: inetOrgPerson
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskQueueMember
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskSIPUser
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskExtension
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: callerid LDAP value: "Andrew CSR" <2001>
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: canreinvite LDAP value: no
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: context LDAP value: manual_dial
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: dtmfmode LDAP value: rfc2833
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: allow LDAP value: ulaw
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstAccountName LDAP value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: nat LDAP value: yes
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: qualify LDAP value: yes
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: type LDAP value: friend
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: host LDAP value: dynamic
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstAccountSecret LDAP value: FF9260DEC84DB1A527FA2C94985C3BEB6E1D45B9
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueInterface LDAP value: SIP/14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueMembername LDAP value: andrew.csr
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueMemberof LDAP value: ApptCenter
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: uid LDAP value: 2001
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstApplication LDAP value: Dial
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstApplicationData LDAP value: SIP/14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstContext LDAP value: AC_Users
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstExtension LDAP value: 2001
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstPriority LDAP value: 1
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: name LDAP value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueuePaused LDAP value: 0
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: ipaddr LDAP value: (null)
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: port LDAP value: (null)
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: regseconds LDAP value: 1331593016
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: defaultuser LDAP value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: lastms LDAP value: 2
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: sn value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: inetOrgPerson
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskQueueMember
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskSIPUser
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskExtension
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: callerid value: "Andrew CSR" <2001>
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: canreinvite value: no
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: context value: manual_dial
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: dtmfmode value: rfc2833
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: allow value: ulaw
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstAccountName value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: nat value: yes
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: qualify value: yes
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: type value: friend
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: host value: dynamic
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstAccountSecret value: FF9260DEC84DB1A527FA2C94985C3BEB6E1D45B9
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueInterface value: SIP/14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueMembername value: andrew.csr
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueMemberof value: ApptCenter
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: uid value: 2001
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstApplication value: Dial
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstApplicationData value: SIP/14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstContext value: AC_Users
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstExtension value: 2001
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstPriority value: 1
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: name value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueuePaused value: 0
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: ipaddr value: (null)
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: port value: (null)
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: regseconds value: 1331593016
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: defaultuser value: 14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: lastms value: 2
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:533 realtime_ldap_result_to_vars: LINE(533) Added to vars - non static
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '(null)' into...
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '(null)' and port ''.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:27751 build_peer: Not an IPv4 nor IPv6 address, cannot get port.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:27754 build_peer: Not an IPv4 nor IPv6 address, cannot set port.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:27756 build_peer: Not an IPv4 nor IPv6 address, cannot get port.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:27759 build_peer: Not an IPv4 nor IPv6 address, cannot set port.
[Mar 12 18:20:25] DEBUG[7868]: db.c:337 ast_db_del: Unable to find key '14484442' in family 'SIP/PeerMethods'
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:27772 build_peer: Bah, we're expired (1409/1331593016/1331594425)!
[Mar 12 18:20:25] DEBUG[7868]: db.c:293 ast_db_get: Unable to find key '14484442' in family 'SIP/Registry'
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:4969 realtime_peer: -REALTIME- loading peer from database to memory. Name: 14484442. Peer objects: 0
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:14065 parse_register_contact: Store REGISTER's src-IP:port for call routing.
    -- Registered SIP '14484442' at 10.1.50.254:61363
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/14484442
PeerStatus: Registered
Address: 10.1.50.254:61363


[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:7768 sip_alloc: Allocating new SIP dialog for 71009b4b5c50ad08576810fa116aef19@10.1.52.57:5060 - OPTIONS (No RTP)
[Mar 12 18:20:25] DEBUG[7868]: acl.c:728 ast_ouraddrfor: For destination '10.1.50.254', our source address is '10.1.52.57'.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3073 initialize_initreq: Initializing initreq for method OPTIONS - callid 30567e9838063eca738e16a933e3c519@10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3344 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.1.50.254:61363
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:702 append_var_and_value_to_filter: name='name' value='14484442'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1319 update_ldap: LINE(1319) Modifying name=14484442 hits: 1
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountIpaddr=10.1.50.254
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountPort=61363
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountExpirationTimestamp=1331594485
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountDefaultuser=14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1324 update_ldap: LINE(1324) deleting AstAccountUserAgent
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountLastms=-1
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountFullContact=sip:14484442@10.86.0.50:61363;ob
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3344 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.1.50.254:61363
[Mar 12 18:20:25] DEBUG[7868]: devicestate.c:491 ast_devstate_changed_literal: ast_devstate_changed_literal Device state change SIP/14484442 0
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:548 do_devstate_changes: do_devstate_changes state change -201319224
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 14484442
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:8088 find_call: = Looking for  Call ID: 30567e9838063eca738e16a933e3c519@10.1.52.57:5060 (Checking To) --From tag as6ec8485f --To-tag z9hG4bK15c353b9
[Mar 12 18:20:25] DEBUG[7871]: chan_sip.c:26317 sip_devicestate: Checking device state for peer 14484442
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:4029 __sip_ack: Stopping retransmission on '30567e9838063eca738e16a933e3c519@10.1.52.57:5060' of Request 102: Match Found
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:458 do_state_change: Changing state for SIP/14484442 - state 5 (Unavailable)
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:438 devstate_event: device 'SIP/14484442' state '5'
[Mar 12 18:20:25] NOTICE[7868]: chan_sip.c:20768 handle_response_peerpoke: Peer '14484442' is now Reachable. (10ms / 2000ms)
[Mar 12 18:20:25] DEBUG[7868]: devicestate.c:491 ast_devstate_changed_literal: ast_devstate_changed_literal Device state change SIP/14484442 0
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:702 append_var_and_value_to_filter: name='name' value='14484442'
[Mar 12 18:20:25] DEBUG[7869]: app_queue.c:1485 handle_statechange: Device 'SIP/14484442' changed to state '5' (Unavailable)
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: ApptCenter
Location: SIP/14484442
MemberName: andrew.csr
Membership: realtime
Penalty: 0
CallsTaken: 0
LastCall: 0
Status: 5
Paused: 0


[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:548 do_devstate_changes: do_devstate_changes state change -201281320
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 14484442
[Mar 12 18:20:25] DEBUG[7871]: chan_sip.c:26317 sip_devicestate: Checking device state for peer 14484442
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:458 do_state_change: Changing state for SIP/14484442 - state 1 (Not in use)
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:438 devstate_event: device 'SIP/14484442' state '1'
[Mar 12 18:20:25] DEBUG[7869]: app_queue.c:1485 handle_statechange: Device 'SIP/14484442' changed to state '1' (Not in use)
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: ApptCenter
Location: SIP/14484442
MemberName: andrew.csr
Membership: realtime
Penalty: 0
CallsTaken: 0
LastCall: 0
Status: 1
Paused: 0


[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1319 update_ldap: LINE(1319) Modifying name=14484442 hits: 1
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountLastms=10
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:6048 sip_destroy: Destroying SIP dialog 30567e9838063eca738e16a933e3c519@10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/14484442
PeerStatus: Reachable
Time: 10


[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:8088 find_call: = Looking for  Call ID: 4989f87ac39d498882ba90e86679be04 (Checking From) --From tag 21f5035e06de41909e1cb2c7962b7bce --To-tag
[Mar 12 18:20:25] DEBUG[7868]: acl.c:728 ast_ouraddrfor: For destination '10.1.50.254', our source address is '10.1.52.57'.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:7768 sip_alloc: Allocating new SIP dialog for 4989f87ac39d498882ba90e86679be04 - REGISTER (No RTP)
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:25049 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.1.50.254:61363' into...
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.1.50.254' and port '61363'.
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.1.52.57' into...
[Mar 12 18:20:25] DEBUG[7868]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.1.52.57' and port ''.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:14065 parse_register_contact: Store REGISTER's src-IP:port for call routing.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:7768 sip_alloc: Allocating new SIP dialog for 4107aec45d65986c4440a98255fff5ad@10.1.52.57:5060 - OPTIONS (No RTP)
[Mar 12 18:20:25] DEBUG[7868]: acl.c:728 ast_ouraddrfor: For destination '10.1.50.254', our source address is '10.1.52.57'.
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3073 initialize_initreq: Initializing initreq for method OPTIONS - callid 0ae9c5f3379cbd301f5a9ab47726ac59@10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/14484442
PeerStatus: Registered
Address: 10.1.50.254:61363


[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3344 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.1.50.254:61363
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:702 append_var_and_value_to_filter: name='name' value='14484442'
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1319 update_ldap: LINE(1319) Modifying name=14484442 hits: 1
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountIpaddr=10.1.50.254
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountPort=61363
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountExpirationTimestamp=1331594485
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountDefaultuser=14484442
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1324 update_ldap: LINE(1324) deleting AstAccountUserAgent
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountLastms=10
[Mar 12 18:20:25] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountFullContact=sip:14484442@10.1.50.254:61363;transport=UDP;ob
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:3344 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.1.50.254:61363
[Mar 12 18:20:25] DEBUG[7868]: devicestate.c:491 ast_devstate_changed_literal: ast_devstate_changed_literal Device state change SIP/14484442 0
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:548 do_devstate_changes: do_devstate_changes state change -201276856
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 14484442
[Mar 12 18:20:25] DEBUG[7871]: chan_sip.c:26317 sip_devicestate: Checking device state for peer 14484442
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:8088 find_call: = Looking for  Call ID: 0ae9c5f3379cbd301f5a9ab47726ac59@10.1.52.57:5060 (Checking To) --From tag as38f48174 --To-tag z9hG4bK1f99d486
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:458 do_state_change: Changing state for SIP/14484442 - state 1 (Not in use)
[Mar 12 18:20:25] DEBUG[7871]: devicestate.c:438 devstate_event: device 'SIP/14484442' state '1'
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:4029 __sip_ack: Stopping retransmission on '0ae9c5f3379cbd301f5a9ab47726ac59@10.1.52.57:5060' of Request 102: Match Found
[Mar 12 18:20:25] DEBUG[7868]: chan_sip.c:6048 sip_destroy: Destroying SIP dialog 0ae9c5f3379cbd301f5a9ab47726ac59@10.1.52.57:5060
[Mar 12 18:20:25] DEBUG[7869]: app_queue.c:1485 handle_statechange: Device 'SIP/14484442' changed to state '1' (Not in use)
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: ApptCenter
Location: SIP/14484442
MemberName: andrew.csr
Membership: realtime
Penalty: 0
CallsTaken: 0
LastCall: 0
Status: 1
Paused: 0


[Mar 12 18:20:25] DEBUG[7906]: manager.c:4623 process_message: Running action 'QueuePause'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:702 append_var_and_value_to_filter: name='uniqueid' value='2001'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:1319 update_ldap: LINE(1319) Modifying uniqueid=2001 hits: 1
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstQueuePaused=1
[Mar 12 18:20:25] DEBUG[7906]: db.c:337 ast_db_del: Unable to find key 'ApptCenter' in family 'Queue/PersistentMembers'
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: QueueMemberPaused
Privilege: agent,all
Queue: ApptCenter
Location: SIP/14484442
MemberName: andrew.csr
Paused: 1
Reason: New Login


[Mar 12 18:20:25] DEBUG[7906]: manager.c:4623 process_message: Running action 'QueueLog'
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4623 process_message: Running action 'QueuePause'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:702 append_var_and_value_to_filter: name='uniqueid' value='2001'
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:1319 update_ldap: LINE(1319) Modifying uniqueid=2001 hits: 1
[Mar 12 18:20:25] DEBUG[7906]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstQueuePaused=0
[Mar 12 18:20:25] DEBUG[7906]: db.c:337 ast_db_del: Unable to find key 'ApptCenter' in family 'Queue/PersistentMembers'
[Mar 12 18:20:25] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: QueueMemberPaused
Privilege: agent,all
Queue: ApptCenter
Location: SIP/14484442
MemberName: andrew.csr
Paused: 0


[Mar 12 18:20:28] DEBUG[7868]: chan_sip.c:8088 find_call: = Looking for  Call ID: 4989f87ac39d498882ba90e86679be04 (Checking From) --From tag ea634abff3114bf09e331fd96c456a38 --To-tag
[Mar 12 18:20:28] DEBUG[7868]: acl.c:728 ast_ouraddrfor: For destination '10.1.50.254', our source address is '10.1.52.57'.
[Mar 12 18:20:28] DEBUG[7868]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.1.52.57:5060
[Mar 12 18:20:28] DEBUG[7868]: chan_sip.c:7768 sip_alloc: Allocating new SIP dialog for 4989f87ac39d498882ba90e86679be04 - REGISTER (No RTP)
[Mar 12 18:20:28] DEBUG[7868]: chan_sip.c:25049 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER
[Mar 12 18:20:28] DEBUG[7868]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.1.50.254:61363' into...
[Mar 12 18:20:28] DEBUG[7868]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.1.50.254' and port '61363'.
[Mar 12 18:20:28] DEBUG[7868]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.1.52.57' into...
[Mar 12 18:20:28] DEBUG[7868]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.1.52.57' and port ''.
    -- Unregistered SIP '14484442'
[Mar 12 18:20:28] DEBUG[7868]: db.c:337 ast_db_del: Unable to find key '14484442' in family 'SIP/PeerMethods'
[Mar 12 18:20:28] DEBUG[7868]: devicestate.c:491 ast_devstate_changed_literal: ast_devstate_changed_literal Device state change SIP/14484442 0
[Mar 12 18:20:28] DEBUG[7868]: chan_sip.c:13712 expire_register: -REALTIME- peer expired registration. Name: 14484442. Realtime peer objects now 0
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:548 do_devstate_changes: do_devstate_changes state change -201275496
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 14484442
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:702 append_var_and_value_to_filter: name='name' value='14484442'
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:26317 sip_devicestate: Checking device state for peer 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:28] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/14484442
PeerStatus: Unregistered
Cause: Expired


[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1319 update_ldap: LINE(1319) Modifying name=14484442 hits: 1
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountIpaddr=(null)
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountPort=(null)
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountExpirationTimestamp=1331594428
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountDefaultuser=14484442
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1324 update_ldap: LINE(1324) deleting AstAccountUserAgent
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountLastms=2
[Mar 12 18:20:28] DEBUG[7868]: res_config_ldap.c:1322 update_ldap: LINE(1322) AstAccountFullContact=sip:14484442@10.1.50.254:61363;transport=UDP;ob
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:702 append_var_and_value_to_filter: name='name' value='14484442'
[Mar 12 18:20:28] DEBUG[7868]: chan_sip.c:3344 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.1.50.254:61363
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:702 append_var_and_value_to_filter: name='host' value='dynamic'
[Mar 12 18:20:28] DEBUG[7868]: devicestate.c:491 ast_devstate_changed_literal: ast_devstate_changed_literal Device state change SIP/14484442 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: sn LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: inetOrgPerson
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskQueueMember
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskSIPUser
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskExtension
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: callerid LDAP value: "Andrew CSR" <2001>
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: canreinvite LDAP value: no
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: context LDAP value: manual_dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: dtmfmode LDAP value: rfc2833
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: allow LDAP value: ulaw
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstAccountName LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: nat LDAP value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: qualify LDAP value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: type LDAP value: friend
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: host LDAP value: dynamic
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstAccountSecret LDAP value: FF9260DEC84DB1A527FA2C94985C3BEB6E1D45B9
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueInterface LDAP value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueMembername LDAP value: andrew.csr
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueMemberof LDAP value: ApptCenter
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: uid LDAP value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstApplication LDAP value: Dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstApplicationData LDAP value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstContext LDAP value: AC_Users
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstExtension LDAP value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstPriority LDAP value: 1
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: name LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueuePaused LDAP value: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: ipaddr LDAP value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: port LDAP value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: regseconds LDAP value: 1331594428
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: defaultuser LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: lastms LDAP value: 2
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: fullcontact LDAP value: sip:14484442@10.1.50.254:61363;transport=UDP;ob
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: sn value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: inetOrgPerson
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskQueueMember
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskSIPUser
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskExtension
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: callerid value: "Andrew CSR" <2001>
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: canreinvite value: no
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: context value: manual_dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: dtmfmode value: rfc2833
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: allow value: ulaw
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstAccountName value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: nat value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: qualify value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: type value: friend
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: host value: dynamic
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstAccountSecret value: FF9260DEC84DB1A527FA2C94985C3BEB6E1D45B9
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueInterface value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueMembername value: andrew.csr
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueMemberof value: ApptCenter
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: uid value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstApplication value: Dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstApplicationData value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstContext value: AC_Users
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstExtension value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstPriority value: 1
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: name value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueuePaused value: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: ipaddr value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: port value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: regseconds value: 1331594428
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: defaultuser value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: lastms value: 2
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:441 realtime_ldap_result_to_vars: LINE(441) is delimited 2 times: sip:14484442@10.1.50.254:61363;transport=UDP;ob
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 1
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 2
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 3
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 4
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 5
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 6
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 7
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 8
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 9
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 10
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 11
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 12
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 13
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 14
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 15
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 16
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 17
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 18
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 19
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 20
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 21
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 22
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 23
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 24
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 25
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 26
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 27
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 28
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 29
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 30
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:455 realtime_ldap_result_to_vars: LINE(455) DELIM - attribute_name: fullcontact value: sip:14484442@10.1.50.254:61363 pos: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 31
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 32
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 33
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 34
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 35
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 36
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 37
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 38
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 39
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 40
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 41
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 42
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 43
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 44
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:455 realtime_ldap_result_to_vars: LINE(455) DELIM - attribute_name: fullcontact value: transport=UDP pos: 31
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 45 i: 45
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 45 i: 46
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:473 realtime_ldap_result_to_vars: LINE(473) DELIM pos: 45 i: 47 delim_count: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:475 realtime_ldap_result_to_vars: LINE(475) DELIM - attribute_name: fullcontact value: ob pos: 45
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:491 realtime_ldap_result_to_vars: LINE(491) DELIM pos: 0 i: 47
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:533 realtime_ldap_result_to_vars: LINE(533) Added to vars - non static
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '(null)' into...
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '(null)' and port ''.
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.1.50.254:61363' into...
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.1.50.254' and port '61363'.
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:27756 build_peer: Not an IPv4 nor IPv6 address, cannot get port.
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:27759 build_peer: Not an IPv4 nor IPv6 address, cannot set port.
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:4969 realtime_peer: -REALTIME- loading peer from database to memory. Name: 14484442. Peer objects: 0
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:4611 sip_destroy_peer: Destroying SIP peer 14484442
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:458 do_state_change: Changing state for SIP/14484442 - state 1 (Not in use)
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:438 devstate_event: device 'SIP/14484442' state '1'
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:548 do_devstate_changes: do_devstate_changes state change -201316136
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 14484442
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:26317 sip_devicestate: Checking device state for peer 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:638 substituted: substituted: string: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:665 cleaned_basedn: basedn: 'dc=showingtime,dc=com' => 'dc=showingtime,dc=com'
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:1736 ldap_reconnect: Everything seems fine.
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:702 append_var_and_value_to_filter: name='name' value='14484442'
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:702 append_var_and_value_to_filter: name='host' value='dynamic'
[Mar 12 18:20:28] DEBUG[7869]: app_queue.c:1485 handle_statechange: Device 'SIP/14484442' changed to state '1' (Not in use)
[Mar 12 18:20:28] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: ApptCenter
Location: SIP/14484442
MemberName: andrew.csr
Membership: realtime
Penalty: 0
CallsTaken: 0
LastCall: 0
Status: 1
Paused: 0


[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: sn LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: inetOrgPerson
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskQueueMember
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskSIPUser
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: objectClass LDAP value: AsteriskExtension
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: callerid LDAP value: "Andrew CSR" <2001>
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: canreinvite LDAP value: no
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: context LDAP value: manual_dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: dtmfmode LDAP value: rfc2833
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: allow LDAP value: ulaw
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstAccountName LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: nat LDAP value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: qualify LDAP value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: type LDAP value: friend
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: host LDAP value: dynamic
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstAccountSecret LDAP value: FF9260DEC84DB1A527FA2C94985C3BEB6E1D45B9
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueInterface LDAP value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueMembername LDAP value: andrew.csr
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueueMemberof LDAP value: ApptCenter
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: uid LDAP value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstApplication LDAP value: Dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstApplicationData LDAP value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstContext LDAP value: AC_Users
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstExtension LDAP value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstPriority LDAP value: 1
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: name LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: AstQueuePaused LDAP value: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: ipaddr LDAP value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: port LDAP value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: regseconds LDAP value: 1331594428
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: defaultuser LDAP value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: lastms LDAP value: 2
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:306 realtime_ldap_entry_to_var: LINE(306) attribute_name: fullcontact LDAP value: sip:14484442@10.1.50.254:61363;transport=UDP;ob
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: sn value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: inetOrgPerson
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskQueueMember
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskSIPUser
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: objectClass value: AsteriskExtension
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: callerid value: "Andrew CSR" <2001>
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: canreinvite value: no
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: context value: manual_dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: dtmfmode value: rfc2833
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: allow value: ulaw
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstAccountName value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: nat value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: qualify value: yes
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: type value: friend
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: host value: dynamic
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstAccountSecret value: FF9260DEC84DB1A527FA2C94985C3BEB6E1D45B9
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueInterface value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueMembername value: andrew.csr
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueueMemberof value: ApptCenter
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: uid value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstApplication value: Dial
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstApplicationData value: SIP/14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstContext value: AC_Users
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstExtension value: 2001
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstPriority value: 1
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: name value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: AstQueuePaused value: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: ipaddr value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: port value: (null)
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: regseconds value: 1331594428
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: defaultuser value: 14484442
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:498 realtime_ldap_result_to_vars: LINE(498) attribute_name: lastms value: 2
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:441 realtime_ldap_result_to_vars: LINE(441) is delimited 2 times: sip:14484442@10.1.50.254:61363;transport=UDP;ob
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 1
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 2
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 3
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 4
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 5
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 6
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 7
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 8
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 9
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 10
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 11
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 12
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 13
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 14
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 15
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 16
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 17
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 18
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 19
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 20
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 21
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 22
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 23
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 24
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 25
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 26
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 27
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 28
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 29
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 0 i: 30
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:455 realtime_ldap_result_to_vars: LINE(455) DELIM - attribute_name: fullcontact value: sip:14484442@10.1.50.254:61363 pos: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 31
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 32
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 33
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 34
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 35
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 36
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 37
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 38
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 39
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 40
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 41
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 42
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 43
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 31 i: 44
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:455 realtime_ldap_result_to_vars: LINE(455) DELIM - attribute_name: fullcontact value: transport=UDP pos: 31
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 45 i: 45
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:451 realtime_ldap_result_to_vars: LINE(451) DELIM pos: 45 i: 46
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:473 realtime_ldap_result_to_vars: LINE(473) DELIM pos: 45 i: 47 delim_count: 0
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:475 realtime_ldap_result_to_vars: LINE(475) DELIM - attribute_name: fullcontact value: ob pos: 45
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:491 realtime_ldap_result_to_vars: LINE(491) DELIM pos: 0 i: 47
[Mar 12 18:20:28] DEBUG[7871]: res_config_ldap.c:533 realtime_ldap_result_to_vars: LINE(533) Added to vars - non static
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '(null)' into...
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '(null)' and port ''.
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '10.1.50.254:61363' into...
[Mar 12 18:20:28] DEBUG[7871]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '10.1.50.254' and port '61363'.
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:27756 build_peer: Not an IPv4 nor IPv6 address, cannot get port.
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:27759 build_peer: Not an IPv4 nor IPv6 address, cannot set port.
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:4969 realtime_peer: -REALTIME- loading peer from database to memory. Name: 14484442. Peer objects: 0
[Mar 12 18:20:28] DEBUG[7871]: chan_sip.c:4611 sip_destroy_peer: Destroying SIP peer 14484442
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:458 do_state_change: Changing state for SIP/14484442 - state 1 (Not in use)
[Mar 12 18:20:28] DEBUG[7871]: devicestate.c:438 devstate_event: device 'SIP/14484442' state '1'
[Mar 12 18:20:28] DEBUG[7869]: app_queue.c:1485 handle_statechange: Device 'SIP/14484442' changed to state '1' (Not in use)
[Mar 12 18:20:28] DEBUG[7906]: manager.c:4216 match_filter: Examining event:
Event: QueueMemberStatus
Privilege: agent,all
Queue: ApptCenter
Location: SIP/14484442
MemberName: andrew.csr
Membership: realtime
Penalty: 0
CallsTaken: 0
LastCall: 0
Status: 1
Paused: 0