'
[Apr 10 13:53:31] DEBUG[30616] pbx.c: Function result is '
Obelisk
Login
(e.g. '1234' not 'tt1234')
Passwort
Sprache
'
[Apr 10 13:53:31] VERBOSE[30616] logger.c: Asterisk Queue Logger restarted
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.100:5060 --->
INVITE sip:1001@10.0.0.5:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bKa9bda80805160dc64
Max-Forwards: 70
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To:
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050576 INVITE
Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, UPDATE
Allow-Events: talk, hold
Contact: "1003"
Supported: replaces, 100rel
User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
X-Siemens-Call-Type: ST-insecure
Content-Type: application/sdp
Content-Length: 316
v=0
o=OpenStage-Line_0 1767075258 111776441 IN IP4 10.0.0.100
s=SIP Call
c=IN IP4 10.0.0.100
t=0 0
m=audio 5010 RTP/AVP 8 0 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=silenceSupp:off - - - -
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=sendrecv
<------------->
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 0 [ 51]: INVITE sip:1001@10.0.0.5:5060;transport=udp SIP/2.0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bKa9bda80805160dc64
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 3 [ 66]: From: "1003" ;tag=89d660b7e5;epid=SC2b129a
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 4 [ 28]: To:
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 5 [ 25]: Call-ID: 515f8d84e1b2dd70
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 6 [ 23]: CSeq: 1536050576 INVITE
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 7 [ 54]: Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, UPDATE
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 8 [ 24]: Allow-Events: talk, hold
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 9 [ 56]: Contact: "1003"
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 10 [ 27]: Supported: replaces, 100rel
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 11 [ 46]: User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 12 [ 32]: X-Siemens-Call-Type: ST-insecure
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 14 [ 19]: Content-Length: 316
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 15 [ 0]:
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 0 [ 3]: v=0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 1 [ 57]: o=OpenStage-Line_0 1767075258 111776441 IN IP4 10.0.0.100
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 2 [ 10]: s=SIP Call
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 3 [ 19]: c=IN IP4 10.0.0.100
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 4 [ 5]: t=0 0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 5 [ 31]: m=audio 5010 RTP/AVP 8 0 18 101
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 10 [ 25]: a=silenceSupp:off - - - -
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 11 [ 19]: a=fmtp:18 annexb=no
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 12 [ 15]: a=fmtp:101 0-15
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 13 [ 10]: a=sendrecv
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: --- (15 headers 14 lines) ---
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: = Looking for Call ID: 515f8d84e1b2dd70 (Checking From) --From tag 89d660b7e5 --To-tag
[Apr 10 13:53:35] DEBUG[21917] acl.c: For destination '10.0.0.100', our source address is '10.0.0.5'.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.0.0.5:5060
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Allocating new SIP dialog for 515f8d84e1b2dd70 - INVITE (No RTP)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Apr 10 13:53:35] DEBUG[21917] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, 100rel"
[Apr 10 13:53:35] DEBUG[21917] sip/reqresp_parser.c: Found SIP option: -replaces-
[Apr 10 13:53:35] DEBUG[21917] sip/reqresp_parser.c: Matched SIP option: replaces
[Apr 10 13:53:35] DEBUG[21917] sip/reqresp_parser.c: Found SIP option: -100rel-
[Apr 10 13:53:35] DEBUG[21917] sip/reqresp_parser.c: Matched SIP option: 100rel
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.100' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.100' and port ''.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Sending to 10.0.0.100:5060 (NAT)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Initializing initreq for method INVITE - callid 515f8d84e1b2dd70
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Using INVITE request as basis request - 515f8d84e1b2dd70
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.5:5060' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.5' and port ''.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found peer '1003' for '1003' from 10.0.0.100:5060
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- Reliably Transmitting (no NAT) to 10.0.0.100:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bKa9bda80805160dc64;received=10.0.0.100
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To: ;tag=as0412a105
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050576 INVITE
Server: Testasterisk
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="224f31f6"
Content-Length: 0
<------------>
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #261
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.0.0.100:5060
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Scheduling destruction of SIP dialog '515f8d84e1b2dd70' in 32000 ms (Method: INVITE)
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.100:5060 --->
ACK sip:1001@10.0.0.5:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bKa9bda80805160dc64
Max-Forwards: 70
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To: ;tag=as0412a105
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050576 ACK
User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
Content-Length: 0
<------------->
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 0 [ 48]: ACK sip:1001@10.0.0.5:5060;transport=udp SIP/2.0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bKa9bda80805160dc64
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 3 [ 66]: From: "1003" ;tag=89d660b7e5;epid=SC2b129a
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 4 [ 43]: To: ;tag=as0412a105
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 5 [ 25]: Call-ID: 515f8d84e1b2dd70
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 6 [ 20]: CSeq: 1536050576 ACK
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 7 [ 46]: User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 8 [ 17]: Content-Length: 0
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: --- (9 headers 0 lines) ---
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: = Looking for Call ID: 515f8d84e1b2dd70 (Checking From) --From tag 89d660b7e5 --To-tag as0412a105
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #261
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Stopping retransmission on '515f8d84e1b2dd70' of Response 1536050576: Match Found
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.100:5060 --->
INVITE sip:1001@10.0.0.5:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bK78012d491d057bec2
Max-Forwards: 70
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To:
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050577 INVITE
Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, UPDATE
Allow-Events: talk, hold
Authorization: Digest username="1003",realm="asterisk",nonce="224f31f6",uri="sip:1001@10.0.0.5:5060;transport=udp",response="f0d53f685751433502bcf36c1f349472",algorithm=MD5
Contact: "1003"
Supported: replaces, 100rel
User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
X-Siemens-Call-Type: ST-insecure
Content-Type: application/sdp
Content-Length: 316
v=0
o=OpenStage-Line_0 1767075258 111776441 IN IP4 10.0.0.100
s=SIP Call
c=IN IP4 10.0.0.100
t=0 0
m=audio 5010 RTP/AVP 8 0 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=silenceSupp:off - - - -
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=sendrecv
<------------->
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 0 [ 51]: INVITE sip:1001@10.0.0.5:5060;transport=udp SIP/2.0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bK78012d491d057bec2
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 3 [ 66]: From: "1003" ;tag=89d660b7e5;epid=SC2b129a
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 4 [ 28]: To:
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 5 [ 25]: Call-ID: 515f8d84e1b2dd70
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 6 [ 23]: CSeq: 1536050577 INVITE
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 7 [ 54]: Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, UPDATE
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 8 [ 24]: Allow-Events: talk, hold
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 9 [172]: Authorization: Digest username="1003",realm="asterisk",nonce="224f31f6",uri="sip:1001@10.0.0.5:5060;transport=udp",response="f0d53f685751433502bcf36c1f349472",algorithm=MD5
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 10 [ 56]: Contact: "1003"
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 11 [ 27]: Supported: replaces, 100rel
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 12 [ 46]: User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 13 [ 32]: X-Siemens-Call-Type: ST-insecure
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 15 [ 19]: Content-Length: 316
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 16 [ 0]:
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 0 [ 3]: v=0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 1 [ 57]: o=OpenStage-Line_0 1767075258 111776441 IN IP4 10.0.0.100
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 2 [ 10]: s=SIP Call
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 3 [ 19]: c=IN IP4 10.0.0.100
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 4 [ 5]: t=0 0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 5 [ 31]: m=audio 5010 RTP/AVP 8 0 18 101
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 10 [ 25]: a=silenceSupp:off - - - -
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 11 [ 19]: a=fmtp:18 annexb=no
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 12 [ 15]: a=fmtp:101 0-15
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Body 13 [ 10]: a=sendrecv
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: --- (16 headers 14 lines) ---
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: = Looking for Call ID: 515f8d84e1b2dd70 (Checking From) --From tag 89d660b7e5 --To-tag
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.5:5060' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.5' and port '5060'.
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.5:5060' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.5' and port '5060'.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.100' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.100' and port ''.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Sending to 10.0.0.100:5060 (no NAT)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Initializing initreq for method INVITE - callid 515f8d84e1b2dd70
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Using INVITE request as basis request - 515f8d84e1b2dd70
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.5:5060' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.5' and port ''.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found peer '1003' for '1003' from 10.0.0.100:5060
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x98aadd0'
[Apr 10 13:53:35] DEBUG[21917] res_rtp_asterisk.c: Allocated port 18788 for RTP instance '0x98aadd0'
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: RTP instance '0x98aadd0' is setup and ready to go
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9702290'
[Apr 10 13:53:35] DEBUG[21917] res_rtp_asterisk.c: Allocated port 16418 for RTP instance '0x9702290'
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: RTP instance '0x9702290' is setup and ready to go
[Apr 10 13:53:35] DEBUG[21917] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9702290'
[Apr 10 13:53:35] VERBOSE[21917] netsock2.c: == Using SIP VIDEO TOS bits 136
[Apr 10 13:53:35] VERBOSE[21917] netsock2.c: == Using SIP VIDEO CoS mark 6
[Apr 10 13:53:35] DEBUG[21917] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x98aadd0'
[Apr 10 13:53:35] VERBOSE[21917] netsock2.c: == Using SIP RTP TOS bits 184
[Apr 10 13:53:35] VERBOSE[21917] netsock2.c: == Using SIP RTP CoS mark 5
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Setting NAT on RTP to Off
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Setting NAT on VRTP to Off
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing session-level SDP o=OpenStage-Line_0 1767075258 111776441 IN IP4 10.0.0.100... OK.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED.
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.100' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.100' and port ''.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing session-level SDP c=IN IP4 10.0.0.100... OK.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found RTP audio format 8
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Setting payload 8 based on m type on 0xb4f6c8e4
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found RTP audio format 0
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Setting payload 0 based on m type on 0xb4f6c8e4
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found RTP audio format 18
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Setting payload 18 based on m type on 0xb4f6c8e4
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found RTP audio format 101
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Setting payload 101 based on m type on 0xb4f6c8e4
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found audio description format PCMA for ID 8
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found audio description format PCMU for ID 0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found audio description format G729 for ID 18
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Found audio description format telephone-event for ID 101
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED OR FAILED.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED OR FAILED.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK.
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Incorporating payload 0 on 0xb4f6c8e4
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Incorporating payload 8 on 0xb4f6c8e4
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Incorporating payload 18 on 0xb4f6c8e4
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Incorporating payload 101 on 0xb4f6c8e4
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Capabilities: us - 0x3c1008 (alaw|g722|h261|h263|h263p|h264), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw)
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[Apr 10 13:53:35] DEBUG[21917] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x98aadd0'
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Peer audio RTP is at port 10.0.0.100:5010
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Copying payload 0 from 0xb4f6c8e4 to 0x98aaf7c
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Copying payload 8 from 0xb4f6c8e4 to 0x98aaf7c
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Copying payload 18 from 0xb4f6c8e4 to 0x98aaf7c
[Apr 10 13:53:35] DEBUG[21917] rtp_engine.c: Copying payload 101 from 0xb4f6c8e4 to 0x98aaf7c
[Apr 10 13:53:35] DEBUG[21917] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x98aadd0'
[Apr 10 13:53:35] DEBUG[21917] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9702290'
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Peer doesn't provide video
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: We're settling with these formats: 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Checking SIP call limits for device 1003
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Updating call counter for incoming call
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Call from peer '1003' is 1 out of 4
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.5:5060' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.5' and port ''.
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: Splitting '10.0.0.5:5060' into...
[Apr 10 13:53:35] DEBUG[21917] netsock2.c: ...host '10.0.0.5' and port ''.
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: Looking for 1001 in default (domain 10.0.0.5)
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1003
[Apr 10 13:53:35] DEBUG[21879] chan_sip.c: Checking device state for peer 1003
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: Changing state for SIP/1003 - state 3 (Busy)
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: device 'SIP/1003' state '3'
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: *** Our native formats are 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: *** Joint capabilities are 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[21880] app_queue.c: Extension '1003@hints' changed to state '3' (Busy) but we don't care because they're not a member of any queue.
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: *** Our capabilities are 0x3c1008 (alaw|g722|h261|h263|h263p|h264)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: This channel can handle video! HOLLYWOOD next!
[Apr 10 13:53:35] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: Newchannel
Privilege: call,all
Channel: SIP/1003-00000003
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 1003
CallerIDName: Lisa Simpson
AccountCode:
Exten: 1001
Context: default
Uniqueid: 1365594815.5
[Apr 10 13:53:35] DEBUG[21944] app_queue.c: Device 'SIP/1003' changed to state '3' (Busy) but we don't care because they're not a member of any queue.
[Apr 10 13:53:35] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 1003
Context: hints
Hint: SIP/1003
Status: 2
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: build_route: Contact hop: "1003"
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: list_route: hop:
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: SIP/1003-00000003: New call is still down.... Trying...
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- Transmitting (no NAT) to 10.0.0.100:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bK78012d491d057bec2;received=10.0.0.100
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To:
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050577 INVITE
Server: Testasterisk
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact:
Content-Length: 0
<------------>
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.0.0.100:5060
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1003
[Apr 10 13:53:35] DEBUG[21879] chan_sip.c: Checking device state for peer 1003
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: Changing state for SIP/1003 - state 3 (Busy)
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: device 'SIP/1003' state '3'
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/1003-00000003
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 1003
CallerIDName: Lisa Simpson
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1365594815.5
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Gosub'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@default:1] Gosub("SIP/1003-00000003", "macro-dial-localext,1001,1(SIP/1001,1001)") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_stack.c: Channel SIP/1003-00000003 has no datastore, so we're allocating one.
[Apr 10 13:53:35] DEBUG[31193] app_stack.c: Setting 'ARG1' to 'SIP/1001'
[Apr 10 13:53:35] DEBUG[31193] app_stack.c: Setting 'ARG2' to '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'SIP/1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:1] NoOp("SIP/1003-00000003", "Calling internal extension SIP/1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:2] Macro("SIP/1003-00000003", "executeagi,callerid.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'callerid.agi?user=1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/callerid.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] DEBUG[21944] app_queue.c: Device 'SIP/1003' changed to state '3' (Busy) but we don't care because they're not a member of any queue.
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/callerid.agi?user=1001 completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:3] GotoIf("SIP/1003-00000003", "1?clstraight:setuserid") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-dial-localext,1001,4)
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'EXTEN' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:4] Set("SIP/1003-00000003", "CONNECTEDLINE(num,i)=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'CALLEDNAME' is 'Marge Simpson'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:5] Set("SIP/1003-00000003", "CONNECTEDLINE(name,i)=Marge Simpson") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:6] Set("SIP/1003-00000003", "CONNECTEDLINE(pres)=allowed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:7] Set("SIP/1003-00000003", "USERID=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'SIP/1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:8] Set("SIP/1003-00000003", "DIALEXTENSION=SIP/1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '1003'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:9] Set("SIP/1003-00000003", "CLIPNUMBER=1003") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:10] Macro("SIP/1003-00000003", "executeagi,clip.agi?type=local") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'clip.agi?type=local'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/clip.agi?type=local") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/clip.agi?type=local completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'CLIPNUMBER' is '1003'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:11] Set("SIP/1003-00000003", "CALLERID(num)=1003") in new stack
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: NewCallerid
Privilege: call,all
Channel: SIP/1003-00000003
CallerIDNum: 1003
CallerIDName: Lisa Simpson
Uniqueid: 1365594815.5
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:12] Macro("SIP/1003-00000003", "executeagi,defaultrules.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'defaultrules.agi?user=1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/defaultrules.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/defaultrules.agi?user=1001 completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'VOICEMAIL' is 'false'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:13] NoOp("SIP/1003-00000003", "VOICEMAIL: false") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'TIMEOUT' is '5'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:14] NoOp("SIP/1003-00000003", "VOICEMAILTIMEOUT: 5") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'FORWARDCONTEXT' is ''
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:15] NoOp("SIP/1003-00000003", "FORWARDCONTEXT: ") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ISFORWARDED' is 'false'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:16] NoOp("SIP/1003-00000003", "ISFORWARDED: false") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ISFORWARDED' is 'false'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:17] GotoIf("SIP/1003-00000003", "0?dial") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ISFORWARDED' is 'false'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:18] GotoIf("SIP/1003-00000003", "1?dial") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-dial-localext,1001,30)
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:30] Macro("SIP/1003-00000003", "executeagi,personal.agi?dialstatus=DIRECT&user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'personal.agi?dialstatus=DIRECT&user=1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/personal.agi?dialstatus=DIRECT&user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/personal.agi?dialstatus=DIRECT&user=1001 completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:31] Macro("SIP/1003-00000003", "executeagi,lookup.agi?user=1001&serverid=1") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'lookup.agi?user=1001&serverid=1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/lookup.agi?user=1001&serverid=1") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/lookup.agi?user=1001&serverid=1 completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:32] Set("SIP/1003-00000003", "CALLS=0") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:33] Set("SIP/1003-00000003", "SOFTCALLS=0") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Evaluating 'CURL(http://10.0.0.5:80/config/sippeers/single,name=web1001&host=dynamic)' (from 'CURL(http://10.0.0.5:80/config/sippeers/single,name=web1001&host=dynamic)}' len 73)
[Apr 10 13:53:35] DEBUG[31193] func_curl.c: Called with data=0xb427efb0, str=0xb4572940, realsize=3684, len=16, used=0
[Apr 10 13:53:35] DEBUG[31193] func_curl.c: Now, len=4096, used=3684
[Apr 10 13:53:35] DEBUG[31193] func_curl.c: str='
Error 500 For input string: "web1001"
HTTP ERROR 500
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Powered by Jetty://
'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '
Error 500 For input string: "web1001"
HTTP ERROR 500
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Powered by Jetty://
'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '
Error 500 For input string: "web1001"
HTTP ERROR 500
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Powered by Jetty://
'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '(null)'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:34] Set("SIP/1003-00000003", "WEBCALLS=") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:35] Set("SIP/1003-00000003", "DECTCALLS=0") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '10.0.0.200'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:36] Set("SIP/1003-00000003", "PHONEIP=10.0.0.200") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '(null)'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:37] Set("SIP/1003-00000003", "SOFTIP=(null)") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Evaluating 'CURL(http://10.0.0.5:80/config/sippeers/single,name=web1001&host=dynamic)' (from 'CURL(http://10.0.0.5:80/config/sippeers/single,name=web1001&host=dynamic)}' len 73)
[Apr 10 13:53:35] DEBUG[31193] func_curl.c: Called with data=0xb427efb0, str=0xb451fda0, realsize=3684, len=16, used=0
[Apr 10 13:53:35] DEBUG[31193] func_curl.c: Now, len=4096, used=3684
[Apr 10 13:53:35] DEBUG[31193] func_curl.c: str='
Error 500 For input string: "web1001"
HTTP ERROR 500
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Powered by Jetty://
'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '
Error 500 For input string: "web1001"
HTTP ERROR 500
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Powered by Jetty://
'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '
Error 500 For input string: "web1001"
HTTP ERROR 500
Problem accessing /config/sippeers/single. Reason:
For input string: "web1001"
Caused by:
java.lang.NumberFormatException: For input string: "web1001"
at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
at java.lang.Integer.parseInt(Integer.java:481)
at java.lang.Integer.valueOf(Integer.java:570)
at de.will.obelisk.web.ConfigServlet.service(ConfigServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
at org.eclipse.jetty.server.Server.handle(Server.java:346)
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589)
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:1065)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:823)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
at java.lang.Thread.run(Thread.java:679)
Powered by Jetty://
'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '(null)'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:38] Set("SIP/1003-00000003", "WEBIP=") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'USERID' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '(null)'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:39] Set("SIP/1003-00000003", "DECTIP=(null)") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'EXTEN' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Gosub'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:40] Gosub("SIP/1003-00000003", "lookup-called-party,s,1(1001)") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_stack.c: Setting 'ARG1' to '1001'
[Apr 10 13:53:35] DEBUG[31193] app_stack.c: Setting 'ARG2' to ''
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:1] Set("SIP/1003-00000003", "LOGGEDINSERVERID=") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:2] Set("SIP/1003-00000003", "LOGGEDINSERVERIP=") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:3] Set("SIP/1003-00000003", "LOGGEDINSERVERNAME=") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:4] Macro("SIP/1003-00000003", "executeagi,lookup.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'lookup.agi?user=1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/lookup.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/lookup.agi?user=1001 completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'LOGGEDINSERVERID' is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:5] Set("SIP/1003-00000003", "CALLEDPARTYLOGGEDINSERVERID=1") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'LOGGEDINSERVERIP' is '10.0.0.5'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:6] Set("SIP/1003-00000003", "CALLEDPARTYLOGGEDINSERVERIP=10.0.0.5") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'LOGGEDINSERVERNAME' is 'asterisk-Testasterisk'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:7] Set("SIP/1003-00000003", "CALLEDPARTYLOGGEDINSERVERNAME=asterisk-Testasterisk") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'CALLEDPARTYLOGGEDINSERVERID' is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'CALLEDPARTYLOGGEDINSERVERIP' is '10.0.0.5'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'CALLEDPARTYLOGGEDINSERVERNAME' is 'asterisk-Testasterisk'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:8] GotoIf("SIP/1003-00000003", "0?lookupfailed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Return'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@lookup-called-party:9] Return("SIP/1003-00000003", "1") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'SERVERID' is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'LOGGEDINSERVERID' is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'LOGGEDINSERVERID' is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Function result is '1003'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'EXTEN' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GosubIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:41] GosubIf("SIP/1003-00000003", "0?lookup-called-user,s,1(1003,1001)") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:42] Macro("SIP/1003-00000003", "executeagi,mobileservice.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'mobileservice.agi?user=1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/mobileservice.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/mobileservice.agi?user=1001 completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'PHONEIP' is '10.0.0.200'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'PHONEIP' is '10.0.0.200'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:43] GotoIf("SIP/1003-00000003", "1?callwaitingcheck") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-dial-localext,1001,47)
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'CALLS' is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:47] GotoIf("SIP/1003-00000003", "0?callwaiting") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'SOFTCALLS' is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:48] GotoIf("SIP/1003-00000003", "0?callwaiting") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'WEBCALLS' is ''
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:49] GotoIf("SIP/1003-00000003", "0?callwaiting") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'DECTCALLS' is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:50] GotoIf("SIP/1003-00000003", "0?callwaiting:execdial") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-dial-localext,1001,54)
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:54] Macro("SIP/1003-00000003", "executeagi,ringtone.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ARG1' is 'ringtone.agi?user=1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/ringtone.agi?user=1001") in new stack
[Apr 10 13:53:35] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script Executing Application: (SipAddHeader) Options: ("Alert-Info: ")
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: SIP Header added ""Alert-Info: "" as __SIPADDHEADER01
[Apr 10 13:53:35] VERBOSE[31193] res_agi.c: -- AGI Script agi://10.0.0.5/ringtone.agi?user=1001 completed, returning 0
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: AGI
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '1'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("SIP/1003-00000003", "1?agisuccess") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("SIP/1003-00000003", "AGI SUCCESS") in new stack
[Apr 10 13:53:35] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'ISFROMGATEWAY' is NULL
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:55] GotoIf("SIP/1003-00000003", "0?setDialOptionExtern") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Set'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:56] Set("SIP/1003-00000003", "DIALOPTIONS=tT") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Goto'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:57] Goto("SIP/1003-00000003", "skipDialOptionsExtern") in new stack
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Goto (macro-dial-localext,1001,59)
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'DIALOPTIONS' is 'tT'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:59] NoOp("SIP/1003-00000003", "Transferoptions: tT") in new stack
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'DIALEXTENSION' is 'SIP/1001'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'TIMEOUT' is '5'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Result of 'DIALOPTIONS' is 'tT'
[Apr 10 13:53:35] DEBUG[31193] pbx.c: Launching 'Dial'
[Apr 10 13:53:35] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:60] Dial("SIP/1003-00000003", "SIP/1001,5,ItT") in new stack
[Apr 10 13:53:35] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Allocating new SIP dialog for 7a225cfe6654a98a0d0438bc07c10439@10.0.0.5:5060 - INVITE (No RTP)
[Apr 10 13:53:35] DEBUG[31193] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x98ec1d0'
[Apr 10 13:53:35] DEBUG[31193] res_rtp_asterisk.c: Allocated port 15220 for RTP instance '0x98ec1d0'
[Apr 10 13:53:35] DEBUG[31193] rtp_engine.c: RTP instance '0x98ec1d0' is setup and ready to go
[Apr 10 13:53:35] DEBUG[31193] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x98ef3a0'
[Apr 10 13:53:35] DEBUG[31193] res_rtp_asterisk.c: Allocated port 13782 for RTP instance '0x98ef3a0'
[Apr 10 13:53:35] DEBUG[31193] rtp_engine.c: RTP instance '0x98ef3a0' is setup and ready to go
[Apr 10 13:53:35] DEBUG[31193] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x98ef3a0'
[Apr 10 13:53:35] VERBOSE[31193] netsock2.c: == Using SIP VIDEO TOS bits 136
[Apr 10 13:53:35] VERBOSE[31193] netsock2.c: == Using SIP VIDEO CoS mark 6
[Apr 10 13:53:35] DEBUG[31193] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x98ec1d0'
[Apr 10 13:53:35] VERBOSE[31193] netsock2.c: == Using SIP RTP TOS bits 184
[Apr 10 13:53:35] VERBOSE[31193] netsock2.c: == Using SIP RTP CoS mark 5
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Setting NAT on RTP to Off
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Setting NAT on VRTP to Off
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: OBPROXY: Not applying OBproxy to this call
[Apr 10 13:53:35] DEBUG[31193] acl.c: For destination '10.0.0.200', our source address is '10.0.0.5'.
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.0.0.5:5060
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: SIP call-id changed from '7a225cfe6654a98a0d0438bc07c10439@10.0.0.5:5060' to '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060'
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: *** Our native formats are 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: Newchannel
Privilege: call,all
Channel: SIP/1001-00000004
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 1001
CallerIDName: Marge Simpson
AccountCode:
Exten:
Context: from-internal-6000999-acl
Uniqueid: 1365594815.6
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: *** Joint capabilities are 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: *** Our capabilities are 0x3c1008 (alaw|g722|h261|h263|h263p|h264)
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw)
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: This channel can handle video! HOLLYWOOD next!
[Apr 10 13:53:35] DEBUG[31193] rtp_engine.c: Seeded SDP of 'SIP/1001-00000004' with that of 'SIP/1003-00000003'
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DIALEDTIME.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable ANSWEREDTIME.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DIALEDPEERNAME.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DIALEDPEERNUMBER.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DIALSTATUS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DIALOPTIONS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable ARG1.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable MACRO_DEPTH.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable AGISTATUS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable AJ_AGISTATUS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Copying hard-transferable variable SIPADDHEADER01.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable GOSUB_RETVAL.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable CALLEDPARTYLOGGEDINSERVERNAME.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable CALLEDPARTYLOGGEDINSERVERIP.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable CALLEDPARTYLOGGEDINSERVERID.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable LOGGEDINSERVERIP.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable LOGGEDINSERVERNAME.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable LOGGEDINSERVERID.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable OUTGOINGSERVERIP.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable OUTGOINGSERVERNAME.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable OUTGOINGSERVERID.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DECTIP.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable WEBIP.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable SOFTIP.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable PHONEIP.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DECTCALLS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable WEBCALLS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable SOFTCALLS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable CALLS.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable CALLWAITING.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable FORWARDCONTEXT.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable FORWARD.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable ISFORWARDED.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable TIMEOUT.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable VOICEMAIL.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable CLIPNUMBER.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable DIALEXTENSION.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable USERID.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable CALLEDNAME.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable ARGC.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable ARG2.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable SIPCALLID.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable SIPDOMAIN.
[Apr 10 13:53:35] DEBUG[31193] channel.c: Not copying variable SIPURI.
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Outgoing Call for 1001
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Updating call counter for outgoing call
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Call to peer '1001' is 1 out of 4
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1001
[Apr 10 13:53:35] DEBUG[21879] chan_sip.c: Checking device state for peer 1001
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: Changing state for SIP/1001 - state 6 (Ringing)
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: device 'SIP/1001' state '6'
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Adding SIP Header "Alert-Info" with content ::
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: This call needs video offers!
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: ** Our capability: 0x3c1008 (alaw|g722|h261|h263|h263p|h264) Video flag: False Text flag: False
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: ** Our prefcodec: 0x8 (alaw)
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Audio is at 15220
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Video is at 10.0.0.5:13782
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Adding codec 0x1000 (g722) to SDP
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Adding video codec 0x40000 (h261) to SDP
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Adding video codec 0x80000 (h263) to SDP
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Adding video codec 0x100000 (h263p) to SDP
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Adding video codec 0x200000 (h264) to SDP
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: -- Done with adding codecs to SDP
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Done building SDP. Settling with this capability: 0x3c1008 (alaw|g722|h261|h263|h263p|h264)
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Initializing initreq for method INVITE - callid 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 0 [ 39]: INVITE sip:1001@10.0.0.200:5060 SIP/2.0
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 1 [ 53]: Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 3 [ 55]: From: "Lisa Simpson" ;tag=as6a72ab50
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 4 [ 30]: To:
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 5 [ 33]: Contact:
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 6 [ 55]: Call-ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 8 [ 24]: User-Agent: Testasterisk
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 9 [ 35]: Date: Wed, 10 Apr 2013 11:53:35 GMT
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 12 [ 77]: Alert-Info:
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 13 [ 55]: P-Asserted-Identity: "Lisa Simpson"
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c: Reliably Transmitting (no NAT) to 10.0.0.200:5060:
INVITE sip:1001@10.0.0.200:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
Max-Forwards: 70
From: "Lisa Simpson" ;tag=as6a72ab50
To:
Contact:
Call-ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
CSeq: 102 INVITE
User-Agent: Testasterisk
Date: Wed, 10 Apr 2013 11:53:35 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Alert-Info:
P-Asserted-Identity: "Lisa Simpson"
Content-Type: application/sdp
Content-Length: 406
v=0
o=root 21763590 21763590 IN IP4 10.0.0.5
s=Asterisk PBX 1.8~svn
c=IN IP4 10.0.0.5
b=CT:128
t=0 0
m=audio 15220 RTP/AVP 8 9 101
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 13782 RTP/AVP 31 34 98 99
a=rtpmap:31 H261/90000
a=rtpmap:34 H263/90000
a=rtpmap:98 h263-1998/90000
a=rtpmap:99 H264/90000
a=sendrecv
---
[Apr 10 13:53:35] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #264
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.0.0.200:5060
[Apr 10 13:53:35] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:35] VERBOSE[31193] app_dial.c: -- Called SIP/1001
[Apr 10 13:53:35] VERBOSE[31193] app_dial.c: -- Connected line update to SIP/1003-00000003 prevented.
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: Dial
Privilege: call,all
SubEvent: Begin
Channel: SIP/1003-00000003
Destination: SIP/1001-00000004
CallerIDNum: 1003
CallerIDName: Lisa Simpson
ConnectedLineNum: 1001
ConnectedLineName: Marge Simpson
UniqueID: 1365594815.5
DestUniqueID: 1365594815.6
Dialstring: 1001
[Apr 10 13:53:35] DEBUG[21944] app_queue.c: Device 'SIP/1001' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Apr 10 13:53:35] DEBUG[21880] app_queue.c: Extension '1001@hints' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 1001
Context: hints
Hint: SIP/1001
Status: 8
[Apr 10 13:53:35] DEBUG[21880] chan_sip.c: Strict routing enforced for session 22118b1946f7f69e
[Apr 10 13:53:35] VERBOSE[21880] chan_sip.c: set_destination: Parsing for address/port to send to
[Apr 10 13:53:35] DEBUG[21880] netsock2.c: Splitting '10.0.0.100:5060' into...
[Apr 10 13:53:35] DEBUG[21880] netsock2.c: ...host '10.0.0.100' and port '5060'.
[Apr 10 13:53:35] VERBOSE[21880] chan_sip.c: set_destination: set destination to 10.0.0.100:5060
[Apr 10 13:53:35] VERBOSE[21880] chan_sip.c: Reliably Transmitting (no NAT) to 10.0.0.100:5060:
NOTIFY sip:1003@10.0.0.100:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK7955566e
Max-Forwards: 70
From: ;tag=as40459a93
To: "1003" ;tag=548b99ced0
Contact:
Call-ID: 22118b1946f7f69e
CSeq: 105 NOTIFY
User-Agent: Testasterisk
Subscription-State: active
Event: dialog
Content-Type: application/dialog-info+xml
Content-Length: 218
---
[Apr 10 13:53:35] DEBUG[21880] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #266
[Apr 10 13:53:35] DEBUG[21880] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 10.0.0.100:5060
[Apr 10 13:53:35] VERBOSE[21880] chan_sip.c: == Extension Changed 1001[hints] new state Ringing for Notify User 1003
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.100:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK7955566e
From: ;tag=as40459a93
To: "1003" ;tag=548b99ced0
Call-ID: 22118b1946f7f69e
CSeq: 105 NOTIFY
Server: OpenStage_60_V3 R0.73.0 SIP 120621
Content-Length: 0
<------------->
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 1 [ 53]: Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK7955566e
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 2 [ 40]: From: ;tag=as40459a93
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 3 [ 50]: To: "1003" ;tag=548b99ced0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 4 [ 25]: Call-ID: 22118b1946f7f69e
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 5 [ 16]: CSeq: 105 NOTIFY
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 6 [ 42]: Server: OpenStage_60_V3 R0.73.0 SIP 120621
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 7 [ 17]: Content-Length: 0
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: --- (8 headers 0 lines) ---
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: = Looking for Call ID: 22118b1946f7f69e (Checking To) --From tag as40459a93 --To-tag 548b99ced0
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Acked pending invite 105
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #266
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Stopping retransmission on '22118b1946f7f69e' of Request 105: Match Found
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.200:5060 --->
SIP/2.0 100 Trying
v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
f: "Lisa Simpson" ;tag=as6a72ab50
t: ;tag=a4iazq7v8i
i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
CSeq: 102 INVITE
m: ;reg-id=1
l: 0
<------------->
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 1 [ 51]: v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 2 [ 52]: f: "Lisa Simpson" ;tag=as6a72ab50
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 3 [ 44]: t: ;tag=a4iazq7v8i
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 4 [ 49]: i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 6 [ 38]: m: ;reg-id=1
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 7 [ 4]: l: 0
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: --- (8 headers 0 lines) ---
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: = Looking for Call ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060 (Checking To) --From tag as6a72ab50 --To-tag a4iazq7v8i
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: *** SIP TIMER: Cancelling retransmission #264 - INVITE (got response)
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' Request 102: Found
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: SIP response 100 to standard invite
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.200:5060 --->
SIP/2.0 180 Ringing
v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
f: "Lisa Simpson" ;tag=as6a72ab50
t: ;tag=a4iazq7v8i
i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
CSeq: 102 INVITE
m: ;reg-id=1
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
l: 0
<------------->
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 1 [ 51]: v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 2 [ 52]: f: "Lisa Simpson" ;tag=as6a72ab50
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 3 [ 44]: t: ;tag=a4iazq7v8i
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 4 [ 49]: i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 6 [ 38]: m: ;reg-id=1
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 7 [ 96]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 8 [ 42]: Allow-Events: talk, hold, refer, call-info
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: Header 9 [ 4]: l: 0
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: --- (10 headers 0 lines) ---
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: = Looking for Call ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060 (Checking To) --From tag as6a72ab50 --To-tag a4iazq7v8i
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' Request 102: Found
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: SIP response 180 to standard invite
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21917] chan_sip.c: build_route: Contact hop: ;reg-id=1
[Apr 10 13:53:35] VERBOSE[21917] chan_sip.c: list_route: hop:
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1001
[Apr 10 13:53:35] DEBUG[21879] chan_sip.c: Checking device state for peer 1001
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: Changing state for SIP/1001 - state 6 (Ringing)
[Apr 10 13:53:35] DEBUG[21879] devicestate.c: device 'SIP/1001' state '6'
[Apr 10 13:53:35] VERBOSE[31193] app_dial.c: -- SIP/1001-00000004 is ringing
[Apr 10 13:53:35] DEBUG[31193] rtp_engine.c: Setting early bridge SDP of 'SIP/1003-00000003' with that of 'SIP/1001-00000004'
[Apr 10 13:53:35] DEBUG[21952] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/1001-00000004
ChannelState: 5
ChannelStateDesc: Ringing
CallerIDNum: 1001
CallerIDName: Marge Simpson
ConnectedLineNum: 1003
ConnectedLineName: Lisa Simpson
Uniqueid: 1365594815.6
[Apr 10 13:53:35] VERBOSE[31193] chan_sip.c:
<--- Transmitting (no NAT) to 10.0.0.100:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bK78012d491d057bec2;received=10.0.0.100
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To: ;tag=as23a2edf1
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050577 INVITE
Server: Testasterisk
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact:
P-Asserted-Identity: "Marge Simpson"
Content-Length: 0
<------------>
[Apr 10 13:53:35] DEBUG[21944] app_queue.c: Device 'SIP/1001' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Apr 10 13:53:35] DEBUG[31193] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 10.0.0.100:5060
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:35] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:35] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:38] DEBUG[21952] manager.c: Running action 'Ping'
[Apr 10 13:53:40] VERBOSE[31193] app_dial.c: -- Nobody picked up in 5000 ms
[Apr 10 13:53:40] DEBUG[31193] channel.c: Hanging up channel 'SIP/1001-00000004'
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Hangup call SIP/1001-00000004, SIP callid 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: update_call_counter(1001) - decrement call limit counter on hangup
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Updating call counter for outgoing call
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Call to peer '1001' removed from call limit 4
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Hanging up channel in state Ringing (not UP)
[Apr 10 13:53:40] DEBUG[31193] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x98ec1d0'
[Apr 10 13:53:40] DEBUG[31193] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x98ef3a0'
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] VERBOSE[31193] chan_sip.c: Scheduling destruction of SIP dialog '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' in 32000 ms (Method: INVITE)
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' Request 102: Found
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Strict routing enforced for session 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] VERBOSE[31193] chan_sip.c: Reliably Transmitting (no NAT) to 10.0.0.200:5060:
CANCEL sip:1001@10.0.0.200:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
Max-Forwards: 70
From: "Lisa Simpson" ;tag=as6a72ab50
To:
Call-ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
CSeq: 102 CANCEL
User-Agent: Testasterisk
Content-Length: 0
---
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #269
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 10.0.0.200:5060
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1001
[Apr 10 13:53:40] DEBUG[21879] chan_sip.c: Checking device state for peer 1001
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: Changing state for SIP/1001 - state 1 (Not in use)
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: device 'SIP/1001' state '1'
[Apr 10 13:53:40] VERBOSE[31193] chan_sip.c: Scheduling destruction of SIP dialog '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' in 32000 ms (Method: INVITE)
[Apr 10 13:53:40] DEBUG[31193] cdr.c: Dropping CDR !
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: SIP/1001-00000004
Uniqueid: 1365594815.6
CallerIDNum: 1001
CallerIDName: Marge Simpson
ConnectedLineNum: 1003
ConnectedLineName: Lisa Simpson
Cause: 16
Cause-txt: Normal Clearing
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1001
[Apr 10 13:53:40] DEBUG[21879] chan_sip.c: Checking device state for peer 1001
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: Changing state for SIP/1001 - state 1 (Not in use)
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: device 'SIP/1001' state '1'
[Apr 10 13:53:40] DEBUG[31193] app_dial.c: Exiting with DIALSTATUS=NOANSWER.
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Dial
Privilege: call,all
SubEvent: End
Channel: SIP/1003-00000003
UniqueID: 1365594815.5
DialStatus: NOANSWER
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Result of 'DIALSTATUS' is 'NOANSWER'
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:61] NoOp("SIP/1003-00000003", "Dial Status: NOANSWER") in new stack
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Result of 'DIALSTATUS' is 'NOANSWER'
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Result of 'ARG2' is '1001'
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Launching 'Macro'
[Apr 10 13:53:40] VERBOSE[31193] pbx.c: -- Executing [1001@macro-dial-localext:62] Macro("SIP/1003-00000003", "executeagi,personal.agi?dialstatus=NOANSWER&user=1001") in new stack
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("SIP/1003-00000003", "Execute AGI") in new stack
[Apr 10 13:53:40] DEBUG[31193] app_macro.c: Executed application: NoOp
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Expression result is '0'
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("SIP/1003-00000003", "0?agihost0failed") in new stack
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31193] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Result of 'ARG1' is 'personal.agi?dialstatus=NOANSWER&user=1001'
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Launching 'AGI'
[Apr 10 13:53:40] VERBOSE[31193] pbx.c: -- Executing [s@macro-executeagi:3] AGI("SIP/1003-00000003", "agi://10.0.0.5/personal.agi?dialstatus=NOANSWER&user=1001") in new stack
[Apr 10 13:53:40] DEBUG[31193] res_agi.c: Wow, connected!
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21880] app_queue.c: Extension '1001@hints' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Apr 10 13:53:40] DEBUG[21880] chan_sip.c: Strict routing enforced for session 22118b1946f7f69e
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 1001
Context: hints
Hint: SIP/1001
Status: 0
[Apr 10 13:53:40] VERBOSE[21880] chan_sip.c: set_destination: Parsing for address/port to send to
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] DEBUG[21880] netsock2.c: Splitting '10.0.0.100:5060' into...
[Apr 10 13:53:40] DEBUG[21880] netsock2.c: ...host '10.0.0.100' and port '5060'.
[Apr 10 13:53:40] VERBOSE[21880] chan_sip.c: set_destination: set destination to 10.0.0.100:5060
[Apr 10 13:53:40] DEBUG[21944] app_queue.c: Device 'SIP/1001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Apr 10 13:53:40] VERBOSE[21880] chan_sip.c: Reliably Transmitting (no NAT) to 10.0.0.100:5060:
NOTIFY sip:1003@10.0.0.100:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK7db7723a
Max-Forwards: 70
From: ;tag=as40459a93
To: "1003" ;tag=548b99ced0
Contact:
Call-ID: 22118b1946f7f69e
CSeq: 106 NOTIFY
User-Agent: Testasterisk
Subscription-State: active
Event: dialog
Content-Type: application/dialog-info+xml
Content-Length: 201
---
[Apr 10 13:53:40] DEBUG[21880] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #271
[Apr 10 13:53:40] DEBUG[21880] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 10.0.0.100:5060
[Apr 10 13:53:40] VERBOSE[21880] chan_sip.c: == Extension Changed 1001[hints] new state Idle for Notify User 1003
[Apr 10 13:53:40] DEBUG[21944] app_queue.c: Device 'SIP/1001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Apr 10 13:53:40] DEBUG[31193] pbx.c: Result of 'BLINDTRANSFER' is NULL
[Apr 10 13:53:40] VERBOSE[31193] res_agi.c: -- AGI Script Executing Application: (SipAddHeader) Options: (Diversion: )
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: SIP Header added "Diversion: " as __SIPADDHEADER02
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.200:5060 --->
SIP/2.0 200 OK
v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
f: "Lisa Simpson" ;tag=as6a72ab50
t: ;tag=a4iazq7v8i
i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
CSeq: 102 CANCEL
l: 0
<------------->
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 1 [ 51]: v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 2 [ 52]: f: "Lisa Simpson" ;tag=as6a72ab50
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 3 [ 44]: t: ;tag=a4iazq7v8i
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 4 [ 49]: i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 5 [ 16]: CSeq: 102 CANCEL
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 6 [ 4]: l: 0
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c: --- (7 headers 0 lines) ---
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: = Looking for Call ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060 (Checking To) --From tag as6a72ab50 --To-tag a4iazq7v8i
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Acked pending invite 102
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #269
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Stopping retransmission on '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' of Request 102: Match Found
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.100:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK7db7723a
From: ;tag=as40459a93
To: "1003" ;tag=548b99ced0
Call-ID: 22118b1946f7f69e
CSeq: 106 NOTIFY
Server: OpenStage_60_V3 R0.73.0 SIP 120621
Content-Length: 0
<------------->
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 1 [ 53]: Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK7db7723a
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 2 [ 40]: From: ;tag=as40459a93
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 3 [ 50]: To: "1003" ;tag=548b99ced0
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 4 [ 25]: Call-ID: 22118b1946f7f69e
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 5 [ 16]: CSeq: 106 NOTIFY
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 6 [ 42]: Server: OpenStage_60_V3 R0.73.0 SIP 120621
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 7 [ 17]: Content-Length: 0
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c: --- (8 headers 0 lines) ---
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: = Looking for Call ID: 22118b1946f7f69e (Checking To) --From tag as40459a93 --To-tag 548b99ced0
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Acked pending invite 106
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #271
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Stopping retransmission on '22118b1946f7f69e' of Request 106: Match Found
[Apr 10 13:53:40] VERBOSE[31193] res_agi.c: -- AGI Script Executing Application: (Dial) Options: (Local/05@from-internal-6000999-acl)
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Newchannel
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;1
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum:
CallerIDName:
AccountCode:
Exten: 05
Context: from-internal-6000999-acl
Uniqueid: 1365594820.7
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Newchannel
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;2
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum:
CallerIDName:
AccountCode:
Exten: 05
Context: from-internal-6000999-acl
Uniqueid: 1365594820.8
[Apr 10 13:53:40] DEBUG[31193] rtp_engine.c: Can't find native functions for channel 'Local/05@from-internal-6000999-acl-00000001;1'
[Apr 10 13:53:40] DEBUG[31193] rtp_engine.c: Seeded SDP of 'Local/05@from-internal-6000999-acl-00000001;1' with that of 'SIP/1003-00000003'
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DIALEDTIME.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable ANSWEREDTIME.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DIALEDPEERNAME.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DIALEDPEERNUMBER.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DIALSTATUS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Copying hard-transferable variable SIPADDHEADER02.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable MACRO_DEPTH.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable ARG1.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable MACRO_PRIORITY.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable MACRO_CONTEXT.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable MACRO_EXTEN.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DIALOPTIONS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable AGISTATUS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable AJ_AGISTATUS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Copying hard-transferable variable SIPADDHEADER01.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable GOSUB_RETVAL.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable CALLEDPARTYLOGGEDINSERVERNAME.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable CALLEDPARTYLOGGEDINSERVERIP.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable CALLEDPARTYLOGGEDINSERVERID.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable LOGGEDINSERVERIP.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable LOGGEDINSERVERNAME.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable LOGGEDINSERVERID.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable OUTGOINGSERVERIP.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable OUTGOINGSERVERNAME.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable OUTGOINGSERVERID.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DECTIP.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable WEBIP.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable SOFTIP.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable PHONEIP.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DECTCALLS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable WEBCALLS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable SOFTCALLS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable CALLS.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable CALLWAITING.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable FORWARDCONTEXT.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable FORWARD.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable ISFORWARDED.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable TIMEOUT.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable VOICEMAIL.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable CLIPNUMBER.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable DIALEXTENSION.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable USERID.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable CALLEDNAME.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable ARGC.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable ARG2.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable SIPCALLID.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable SIPDOMAIN.
[Apr 10 13:53:40] DEBUG[31193] channel.c: Not copying variable SIPURI.
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: NewCallerid
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;1
CallerIDNum: 1001
CallerIDName: Marge Simpson
Uniqueid: 1365594820.7
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[Apr 10 13:53:40] VERBOSE[31193] app_dial.c: -- Called Local/05@from-internal-6000999-acl
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'EXTEN' is '05'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:1] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "ACL check for 1003 - destination 05") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Set'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:2] Set("Local/05@from-internal-6000999-acl-00000001;2", "_CALLER=1003") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'EXTEN' is '05'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Set'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:3] Set("Local/05@from-internal-6000999-acl-00000001;2", "CALLEDNUMBER=05") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Macro'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:4] Macro("Local/05@from-internal-6000999-acl-00000001;2", "executeagi,set-callerid.agi") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Execute AGI") in new stack
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?agihost0failed") in new stack
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Dial
Privilege: call,all
SubEvent: Begin
Channel: SIP/1003-00000003
Destination: Local/05@from-internal-6000999-acl-00000001;1
CallerIDNum: 1003
CallerIDName: Lisa Simpson
ConnectedLineNum: 1001
ConnectedLineName: Marge Simpson
UniqueID: 1365594815.5
DestUniqueID: 1365594820.7
Dialstring: 05@from-internal-6000999-acl
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'ARG1' is 'set-callerid.agi'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'AGI'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:3] AGI("Local/05@from-internal-6000999-acl-00000001;2", "agi://10.0.0.5/set-callerid.agi") in new stack
[Apr 10 13:53:40] DEBUG[31196] res_agi.c: Wow, connected!
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'CALLER' is '1003'
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: NewCallerid
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;2
CallerIDNum: 1003
CallerIDName: Lisa Simpson (1003)
Uniqueid: 1365594820.8
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[Apr 10 13:53:40] VERBOSE[31196] res_agi.c: -- AGI Script agi://10.0.0.5/set-callerid.agi completed, returning 0
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: AGI
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '1'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "1?agisuccess") in new stack
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "AGI SUCCESS") in new stack
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'CALLER' is '1003'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'SIPAddHeader'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:5] SIPAddHeader("Local/05@from-internal-6000999-acl-00000001;2", "Call-Info: ;purpose=icon") in new stack
[Apr 10 13:53:40] DEBUG[31196] chan_sip.c: SIP Header added "Call-Info: ;purpose=icon" as __SIPADDHEADER03
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is '0'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:6] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "REDIRECTINGCOUNT = 0") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'FORWARDARRAY' is NULL
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:7] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "FORWARDARRAY = ") in new stack
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.200:5060 --->
SIP/2.0 487 Request Terminated
v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
f: "Lisa Simpson" ;tag=as6a72ab50
t: ;tag=a4iazq7v8i
i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
CSeq: 102 INVITE
m: ;reg-id=1
l: 0
<------------->
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is ''
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 0 [ 30]: SIP/2.0 487 Request Terminated
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 1 [ 51]: v: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is ''
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 2 [ 52]: f: "Lisa Simpson" ;tag=as6a72ab50
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 3 [ 44]: t: ;tag=a4iazq7v8i
[Apr 10 13:53:40] DEBUG[31196] func_strings.c: c1=48, c2=57
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 4 [ 49]: i: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:40] DEBUG[31196] func_strings.c: Allowed: 0123456789
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is ''
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 6 [ 38]: m: ;reg-id=1
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 7 [ 4]: l: 0
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '1'
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c: --- (8 headers 0 lines) ---
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:8] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "1?acl") in new stack
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: = Looking for Call ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060 (Checking To) --From tag as6a72ab50 --To-tag a4iazq7v8i
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Goto (from-internal-6000999-acl,05,14)
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'CALLER' is '1003'
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Stopping retransmission on '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' of Request 102: Match Found
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'CALLEDNUMBER' is '05'
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: SIP response 487 to standard invite
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Macro'
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Strict routing enforced for session 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:14] Macro("Local/05@from-internal-6000999-acl-00000001;2", "executeagi,acl.agi?user=1003&callednum=05") in new stack
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c: Transmitting (no NAT) to 10.0.0.200:5060:
ACK sip:1001@10.0.0.200:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.5:5060;branch=z9hG4bK158dbb19
Max-Forwards: 70
From: "Lisa Simpson" ;tag=as6a72ab50
To: ;tag=a4iazq7v8i
Contact:
Call-ID: 51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060
CSeq: 102 ACK
User-Agent: Testasterisk
Content-Length: 0
---
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Trying to put 'ACK sip:100' onto UDP socket destined for 10.0.0.200:5060
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Updating call counter for outgoing call
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Call to peer '1001' removed from call limit 4
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c: Scheduling destruction of SIP dialog '51f335e4008fc36e540f3b5231a22fc5@10.0.0.5:5060' in 32000 ms (Method: INVITE)
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Execute AGI") in new stack
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1001
[Apr 10 13:53:40] DEBUG[21879] chan_sip.c: Checking device state for peer 1001
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: Changing state for SIP/1001 - state 1 (Not in use)
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: device 'SIP/1001' state '1'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?agihost0failed") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:40] DEBUG[21944] app_queue.c: Device 'SIP/1001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'ARG1' is 'acl.agi?user=1003&callednum=05'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'AGI'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:3] AGI("Local/05@from-internal-6000999-acl-00000001;2", "agi://10.0.0.5/acl.agi?user=1003&callednum=05") in new stack
[Apr 10 13:53:40] DEBUG[31196] res_agi.c: Wow, connected!
[Apr 10 13:53:40] VERBOSE[31196] res_agi.c: -- AGI Script agi://10.0.0.5/acl.agi?user=1003&callednum=05 completed, returning 0
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: AGI
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '1'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "1?agisuccess") in new stack
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "AGI SUCCESS") in new stack
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'CALLER' is '1003'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'CALLEDNUMBER' is '05'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Macro'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:15] Macro("Local/05@from-internal-6000999-acl-00000001;2", "executeagi,diallog.agi?user=1003&type=0&number=05") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Execute AGI") in new stack
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?agihost0failed") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'ARG1' is 'diallog.agi?user=1003&type=0&number=05'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'AGI'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:3] AGI("Local/05@from-internal-6000999-acl-00000001;2", "agi://10.0.0.5/diallog.agi?user=1003&type=0&number=05") in new stack
[Apr 10 13:53:40] DEBUG[31196] res_agi.c: Wow, connected!
[Apr 10 13:53:40] VERBOSE[31196] res_agi.c: -- AGI Script agi://10.0.0.5/diallog.agi?user=1003&type=0&number=05 completed, returning 0
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: AGI
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '1'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "1?agisuccess") in new stack
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "AGI SUCCESS") in new stack
[Apr 10 13:53:40] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Result of 'CALLEDNUMBER' is '05'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999-acl:16] Goto("Local/05@from-internal-6000999-acl-00000001;2", "from-internal-6000999,05,1") in new stack
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Goto (from-internal-6000999,05,1)
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [05@from-internal-6000999:1] Goto("Local/05@from-internal-6000999-acl-00000001;2", "local-queues,75111,1") in new stack
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,1)
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:1] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "ServiceDesk - caller 1003 going to be queued") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:2] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,sat,*,*?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:3] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,sun,*,*?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:4] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,25-26,dec?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:5] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,01,jan?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:6] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,01,may?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:7] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,03,oct?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:8] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,09,may?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:9] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,29,mar?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:10] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,01,apr?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:11] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "*,*,20,may?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:12] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "13:00-06:00,*,24,dec?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:13] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "13:00-06:00,*,31,dec?servicestandby,s,1") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is 'Lisa Simpson (1003)'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is '0'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Expression result is '1'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:14] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "1?fixcallerid") in new stack
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,16)
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:16] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Setting up CallerIDName for Agents") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is 'Lisa Simpson (1003)'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Set'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:17] Set("Local/05@from-internal-6000999-acl-00000001;2", "ONLYCALLERIDNAME=Lisa Simpson (1003)") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Function result is 'Lisa Simpson (1003)'
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Set'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:18] Set("Local/05@from-internal-6000999-acl-00000001;2", "CALLERID(name)=C: Lisa Simpson (1003)") in new stack
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Answer'
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: NewCallerid
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;2
CallerIDNum: 1003
CallerIDName: C: Lisa Simpson (1003)
Uniqueid: 1365594820.8
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:19] Answer("Local/05@from-internal-6000999-acl-00000001;2", "") in new stack
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for Local - 05@from-internal-6000999-acl
[Apr 10 13:53:40] DEBUG[21879] chan_local.c: Checking if extension 05@from-internal-6000999-acl exists (devicestate)
[Apr 10 13:53:40] DEBUG[31196] chan_local.c: Blocked indication -1
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;2
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1003
CallerIDName: C: Lisa Simpson (1003)
ConnectedLineNum: 1001
ConnectedLineName: Marge Simpson
Uniqueid: 1365594820.8
[Apr 10 13:53:40] VERBOSE[31193] app_dial.c: -- Local/05@from-internal-6000999-acl-00000001;1 answered SIP/1003-00000003
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: Changing state for Local/05@from-internal-6000999-acl - state 2 (In use)
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: device 'Local/05@from-internal-6000999-acl' state '2'
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for Local - 05@from-internal-6000999-acl
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;1
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1001
CallerIDName: Marge Simpson
ConnectedLineNum: 1003
ConnectedLineName: Lisa Simpson
Uniqueid: 1365594820.7
[Apr 10 13:53:40] DEBUG[21879] chan_local.c: Checking if extension 05@from-internal-6000999-acl exists (devicestate)
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: Changing state for Local/05@from-internal-6000999-acl - state 2 (In use)
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: device 'Local/05@from-internal-6000999-acl' state '2'
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: SIP answering channel: SIP/1003-00000003
[Apr 10 13:53:40] DEBUG[31193] res_rtp_asterisk.c: Setting the marker bit due to a source update
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/1003-00000003
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1003
CallerIDName: Lisa Simpson
ConnectedLineNum: 1001
ConnectedLineName: Marge Simpson
Uniqueid: 1365594815.5
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: No provider found, checking channel drivers for SIP - 1003
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Setting framing from config on incoming call
[Apr 10 13:53:40] DEBUG[21879] chan_sip.c: Checking device state for peer 1003
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: Changing state for SIP/1003 - state 3 (Busy)
[Apr 10 13:53:40] DEBUG[21879] devicestate.c: device 'SIP/1003' state '3'
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[Apr 10 13:53:40] VERBOSE[31193] chan_sip.c: Audio is at 18788
[Apr 10 13:53:40] VERBOSE[31193] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Apr 10 13:53:40] VERBOSE[31193] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: -- Done with adding codecs to SDP
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw)
[Apr 10 13:53:40] VERBOSE[31193] chan_sip.c:
<--- Reliably Transmitting (no NAT) to 10.0.0.100:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bK78012d491d057bec2;received=10.0.0.100
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To: ;tag=as23a2edf1
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050577 INVITE
Server: Testasterisk
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact:
P-Asserted-Identity: "Marge Simpson"
Content-Type: application/sdp
Content-Length: 228
v=0
o=root 1577189581 1577189581 IN IP4 10.0.0.5
s=Asterisk PBX 1.8~svn
c=IN IP4 10.0.0.5
t=0 0
m=audio 18788 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
<------------>
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #273
[Apr 10 13:53:40] DEBUG[31193] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.0.0.100:5060
[Apr 10 13:53:40] DEBUG[31193] features.c: bridge answer set, chan answer set
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: NewAccountCode
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;1
Uniqueid: 1365594820.7
AccountCode:
OldAccountCode:
[Apr 10 13:53:40] DEBUG[31193] features.c: Removing dialed interfaces datastore on Local/05@from-internal-6000999-acl-00000001;1 since we're bridging
[Apr 10 13:53:40] DEBUG[21952] manager.c: Examining event:
Event: Bridge
Privilege: call,all
Bridgestate: Link
Bridgetype: core
Channel1: SIP/1003-00000003
Channel2: Local/05@from-internal-6000999-acl-00000001;1
Uniqueid1: 1365594815.5
Uniqueid2: 1365594820.7
CallerID1: 1003
CallerID2: 1001
[Apr 10 13:53:40] DEBUG[31193] res_rtp_asterisk.c: Setting the marker bit due to a source update
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21944] app_queue.c: Device 'Local/05@from-internal-6000999-acl' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Apr 10 13:53:40] DEBUG[21944] app_queue.c: Device 'Local/05@from-internal-6000999-acl' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Apr 10 13:53:40] DEBUG[21944] app_queue.c: Device 'SIP/1003' changed to state '3' (Busy) but we don't care because they're not a member of any queue.
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] DEBUG[21874] cel_radius.c: Unable to create RADIUS record. CEL not recorded!
[Apr 10 13:53:40] DEBUG[21874] cel_pgsql.c: inserting a CEL record.
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c:
<--- SIP read from UDP:10.0.0.100:5060 --->
ACK sip:1001@10.0.0.5:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bK94132c2557d182ee2
Max-Forwards: 70
From: "1003" ;tag=89d660b7e5;epid=SC2b129a
To: ;tag=as23a2edf1
Call-ID: 515f8d84e1b2dd70
CSeq: 1536050577 ACK
Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, UPDATE
Allow-Events: talk, hold
Authorization: Digest username="1003",realm="asterisk",nonce="224f31f6",uri="sip:1001@10.0.0.5:5060;transport=udp",response="f0d53f685751433502bcf36c1f349472",algorithm=MD5
User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
Content-Length: 0
<------------->
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 0 [ 34]: ACK sip:1001@10.0.0.5:5060 SIP/2.0
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.0.0.100;branch=z9hG4bK94132c2557d182ee2
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 3 [ 66]: From: "1003" ;tag=89d660b7e5;epid=SC2b129a
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 4 [ 43]: To: ;tag=as23a2edf1
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 5 [ 25]: Call-ID: 515f8d84e1b2dd70
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 6 [ 20]: CSeq: 1536050577 ACK
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 7 [ 54]: Allow: INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, UPDATE
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 8 [ 24]: Allow-Events: talk, hold
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 9 [172]: Authorization: Digest username="1003",realm="asterisk",nonce="224f31f6",uri="sip:1001@10.0.0.5:5060;transport=udp",response="f0d53f685751433502bcf36c1f349472",algorithm=MD5
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 10 [ 46]: User-Agent: OpenStage_60_V3 R0.73.0 SIP 120621
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Header 11 [ 17]: Content-Length: 0
[Apr 10 13:53:40] VERBOSE[21917] chan_sip.c: --- (12 headers 0 lines) ---
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: = Looking for Call ID: 515f8d84e1b2dd70 (Checking From) --From tag 89d660b7e5 --To-tag as23a2edf1
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #273
[Apr 10 13:53:40] DEBUG[21917] chan_sip.c: Stopping retransmission on '515f8d84e1b2dd70' of Response 1536050577: Match Found
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[21952] manager.c: Running action 'Getvar'
[Apr 10 13:53:40] DEBUG[21952] pbx.c: Result of 'AJ_TRACE_ID' is NULL
[Apr 10 13:53:40] DEBUG[31196] pbx.c: Launching 'Wait'
[Apr 10 13:53:40] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:20] Wait("Local/05@from-internal-6000999-acl-00000001;2", "1") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIfTime'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:21] GotoIfTime("Local/05@from-internal-6000999-acl-00000001;2", "18:30-06:00,mon-fri,*,*?servicestandby,s,1") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:22] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "ServiceDesk for VIP - caller 1003 going to be queued") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:23] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:24] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:25] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:26] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:27] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:28] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:29] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:30] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:31] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:32] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGFuldaITHotlineVIP") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,36)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:36] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level VIP") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:37] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "===========> IT-Service Desk-Hotline - CallerID des Anrufers: 1003") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '1'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:38] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "1?checkcallerid") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,40)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:40] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "===========> IT-Service Desk-Hotline - Setze mittels des AGIs set-callerid die externe CallerID") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Macro'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:41] Macro("Local/05@from-internal-6000999-acl-00000001;2", "executeagi,set-callerid.agi?type=external") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:1] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Execute AGI") in new stack
[Apr 10 13:53:41] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Result of 'AGIHOST0' is NULL
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:2] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?agihost0failed") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Result of 'ARG1' is 'set-callerid.agi?type=external'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'AGI'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:3] AGI("Local/05@from-internal-6000999-acl-00000001;2", "agi://10.0.0.5/set-callerid.agi?type=external") in new stack
[Apr 10 13:53:41] DEBUG[31196] res_agi.c: Wow, connected!
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Result of 'CALLER' is '1003'
[Apr 10 13:53:41] VERBOSE[31196] res_agi.c: -- AGI Script agi://10.0.0.5/set-callerid.agi?type=external completed, returning 0
[Apr 10 13:53:41] DEBUG[31196] app_macro.c: Executed application: AGI
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '1'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:4] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "1?agisuccess") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (macro-executeagi,s,7)
[Apr 10 13:53:41] DEBUG[31196] app_macro.c: Executed application: GotoIf
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Result of 'AGISTATUS' is 'SUCCESS'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [s@macro-executeagi:7] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "AGI SUCCESS") in new stack
[Apr 10 13:53:41] DEBUG[31196] app_macro.c: Executed application: NoOp
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '1003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Set'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:42] Set("Local/05@from-internal-6000999-acl-00000001;2", "CALLERID(num)=001003") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is 'C: Lisa Simpson (1003)'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Set'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:43] Set("Local/05@from-internal-6000999-acl-00000001;2", "CALLERID(name)=C: C: Lisa Simpson (1003)") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[21952] manager.c: Examining event:
Event: NewCallerid
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;2
CallerIDNum: 001003
CallerIDName: C: C: Lisa Simpson (1003)
Uniqueid: 1365594820.8
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:44] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "===========> IT-Service Desk-Hotline - Aendere CallerID des Anrufers: 001003") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is 'C: C: Lisa Simpson (1003)'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:45] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "===========> IT-Service Desk-Hotline - CallerID Name des Anrufers: C: C: Lisa Simpson (1003)") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:46] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "===========> IT-Service Desk-Hotline - Gehe weiter...") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:47] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGFuldaITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:48] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGFuldaITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,51)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:51] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:52] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGEisenachITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:53] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGEisenachITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,56)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:56] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:57] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGIngolstadtITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:58] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGIngolstadtITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,61)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:61] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:62] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGSindelfingenITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:63] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGSindelfingenITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,66)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:66] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:67] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGWolfsburgITHoltline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:68] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGWolfsburgITHoltline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,71)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:71] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:72] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGMuenchenITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:73] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGMuenchenITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,76)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:76] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:77] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGRuesselsheimITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:78] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGRuesselsheimITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,81)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:81] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:82] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGAustralienITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:83] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGAustralienITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,86)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:86] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:87] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGIWestITHoltline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:88] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGIWestITHoltline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,91)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:91] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '001003'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Expression result is '0'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'GotoIf'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:92] GotoIf("Local/05@from-internal-6000999-acl-00000001;2", "0?queue-EDAGKoelnITHotline") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Not taking any branch
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Goto'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:93] Goto("Local/05@from-internal-6000999-acl-00000001;2", "endqueue-EDAGKoelnITHotline") in new stack
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Goto (local-queues,75111,96)
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'NoOp'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:96] NoOp("Local/05@from-internal-6000999-acl-00000001;2", "Caller reached main service desk - first level") in new stack
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Launching 'Queue'
[Apr 10 13:53:41] VERBOSE[31196] pbx.c: -- Executing [75111@local-queues:97] Queue("Local/05@from-internal-6000999-acl-00000001;2", "EDAGITFirstLevelSupport,tr,,,71") in new stack
[Apr 10 13:53:41] DEBUG[31196] app_queue.c: NO QUEUE_PRIO variable found. Using default.
[Apr 10 13:53:41] DEBUG[31196] app_queue.c: queue: EDAGITFirstLevelSupport, options: tr, url: , announce: , expires: 1365594892, priority: 0
[Apr 10 13:53:41] DEBUG[31196] app_queue.c: Queue EDAGITFirstLevelSupport has no realtime members defined. No need for update
[Apr 10 13:53:41] DEBUG[31196] app_queue.c: SIP/1000 is available.
[Apr 10 13:53:41] DEBUG[31196] app_queue.c: Queue 'EDAGITFirstLevelSupport' Join, Channel 'Local/05@from-internal-6000999-acl-00000001;2', Position '1'
[Apr 10 13:53:41] DEBUG[21952] manager.c: Examining event:
Event: Join
Privilege: call,all
Channel: Local/05@from-internal-6000999-acl-00000001;2
CallerIDNum: 001003
CallerIDName: C: C: Lisa Simpson (1003)
ConnectedLineNum: 1001
ConnectedLineName: Marge Simpson
Queue: EDAGITFirstLevelSupport
Position: 1
Count: 1
Uniqueid: 1365594820.8
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Evaluating 'CURL(http://10.0.0.5:80/queuelogger/require,data1=char%3A0&data2=char%3A6&data3=char%3A1&data4=char%3A0&data5=char%3A0)' (from 'CURL(http://10.0.0.5:80/queuelogger/require,data1=char%3A0&data2=char%3A6&data3=char%3A1&data4=char%3A0&data5=char%3A0)}' len 119)
[Apr 10 13:53:41] DEBUG[31196] func_curl.c: Called with data=0xb4242350, str=0x98819b0, realsize=1463, len=16, used=0
[Apr 10 13:53:41] DEBUG[31196] func_curl.c: Now, len=2048, used=1463
[Apr 10 13:53:41] DEBUG[31196] func_curl.c: str='
Obelisk
Login
(e.g. '1234' not 'tt1234')
Passwort
Sprache
'
[Apr 10 13:53:41] DEBUG[31196] pbx.c: Function result is '
Obelisk