Ticket #997: log.txt

File log.txt, 48.1 KB (added by bennylp, 11 years ago)
Line 
1 13:51:59.293 sip_endpoint.c  Module "mod-pjsua-log" registered
2 13:51:59.293 sip_endpoint.c  Module "mod-tsx-layer" registered
3 13:51:59.293 sip_endpoint.c  Module "mod-stateful-util" registered
4 13:51:59.299 sip_endpoint.c  Module "mod-ua" registered
5 13:51:59.299 sip_endpoint.c  Module "mod-100rel" registered
6 13:51:59.299 sip_endpoint.c  Module "mod-pjsua" registered
7 13:51:59.299 sip_endpoint.c  Module "mod-invite" registered
8 13:51:59.430       pa_dev.c  PortAudio sound library initialized, status=0
9 13:51:59.430       pa_dev.c  PortAudio host api count=1
10 13:51:59.430       pa_dev.c  Sound device count=7
11 13:51:59.430          pjlib  select() I/O Queue created (0x1818814)
12 13:51:59.430   conference.c  Creating conference bridge with 254 ports
13 13:51:59.447 sip_endpoint.c  Module "mod-evsub" registered
14 13:51:59.447 sip_endpoint.c  Module "mod-presence" registered
15 13:51:59.447        evsub.c  Event pkg "presence" registered by mod-presence
16 13:51:59.447 sip_endpoint.c  Module "mod-mwi" registered
17 13:51:59.447        evsub.c  Event pkg "message-summary" registered by mod-mwi
18 13:51:59.447 sip_endpoint.c  Module "mod-refer" registered
19 13:51:59.447        evsub.c  Event pkg "refer" registered by mod-refer
20 13:51:59.447 sip_endpoint.c  Module "mod-pjsua-pres" registered
21 13:51:59.447 sip_endpoint.c  Module "mod-pjsua-im" registered
22 13:51:59.447 sip_endpoint.c  Module "mod-pjsua-options" registered
23 13:51:59.447   pjsua_core.c  1 SIP worker threads created
24 13:51:59.447   pjsua_core.c  pjsua version 1.5 for i386-apple-darwin8.11.1 initialized
25 13:51:59.447 sip_endpoint.c  Module "mod-default-handler" registered
26 13:51:59.448   pjsua_core.c  SIP UDP socket reachable at 10.127.1.99:5060
27 13:51:59.448 sip_transport_  Error setting SO_RCVBUF: No buffer space available [120055]
28 13:51:59.448 sip_transport_  Error setting SO_SNDBUF: No buffer space available [120055]
29 13:51:59.448   udp0x181f400  SIP UDP transport started, published address is 10.127.1.99:5060
30 13:51:59.448    pjsua_acc.c  Account <sip:10.127.1.99:5060> added with id 0
31 13:51:59.448    tcplis:5060  SIP TCP listener ready for incoming connections at 10.127.1.99:5060
32 13:51:59.448    pjsua_acc.c  Account <sip:10.127.1.99:5060;transport=TCP> added with id 1
33 13:51:59.448    pjsua_acc.c  Account sip:4414@sip.example.com added with id 2
34 13:51:59.448       endpoint  Request msg REGISTER/cseq=20721 (tdta0x182d400) created.
35 13:51:59.448   tsx0x182aa64  Transaction created for Request msg REGISTER/cseq=20722 (tdta0x182d400)
36 13:51:59.448   tsx0x182aa64  Sending Request msg REGISTER/cseq=20722 (tdta0x182d400) in state Null
37 13:51:59.448  sip_resolve.c  DNS resolver not available, target 'sip.example.com:0' type=Unspecified will be resolved with gethostbyname()
38 13:51:59.449  sip_resolve.c  Target 'sip.example.com:0' type=Unspecified resolved to '173.8.19.148:5060' type=UDP (UDP transport)
39 13:51:59.449   pjsua_core.c  TX 460 bytes Request msg REGISTER/cseq=20722 (tdta0x182d400) to UDP 173.8.19.148:5060:
40REGISTER sip:sip.example.com SIP/2.0
41Via: SIP/2.0/UDP 10.127.1.99:5060;rport;branch=z9hG4bKPj9129820D-75BA-404C-A8F4-0CD951872DF2
42Max-Forwards: 70
43From: <sip:4414@sip.example.com>;tag=839BF07A-93EE-47D4-8008-4F019ACEB257
44To: <sip:4414@sip.example.com>
45Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
46CSeq: 20722 REGISTER
47User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
48Contact: <sip:4414@10.127.1.99:5060>
49Expires: 300
50Content-Length:  0
51
52
53--end msg--
54 13:51:59.449   tsx0x182aa64  State changed from Null to Calling, event=TX_MSG
55 13:51:59.449    pjsua_acc.c  Registration sent
56 13:51:59.449        _krtp.c  pjmedia_transport_krtp_create
57 13:51:59.449        _krtp.c  Coalesce Count 3 3
58 13:51:59.450        _krtp.c  pjmedia_transport_krtp_create
59 13:51:59.450        _krtp.c  Coalesce Count 3 3
60 13:51:59.450        _krtp.c  pjmedia_transport_krtp_create
61 13:51:59.450        _krtp.c  Coalesce Count 3 3
62 13:51:59.450        _krtp.c  pjmedia_transport_krtp_create
63 13:51:59.450        _krtp.c  Coalesce Count 3 3
64 13:51:59.451 sip_endpoint.c  Module "mod-unsolicited-mwi" registered
65 13:51:59.466 sip_endpoint.c  Processing incoming message: Request msg OPTIONS/cseq=102 (rdata0x182b664)
66 13:51:59.466   pjsua_core.c  RX 535 bytes Request msg OPTIONS/cseq=102 (rdata0x182b664) from UDP 173.8.19.148:5060:
67OPTIONS sip:4414@66.219.174.73:5060;transport=UDP SIP/2.0
68Via: SIP/2.0/UDP 173.8.19.148:5060;branch=z9hG4bK568a3c49;rport
69From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as2b1f0eea
70To: <sip:4414@66.219.174.73:5060;transport=UDP>
71Contact: <sip:Unknown@173.8.19.148>
72Call-ID: 7a08c2d543456a5b22e920cf1ebef829@173.8.19.148
73CSeq: 102 OPTIONS
74User-Agent: Asterisk PBX
75Max-Forwards: 70
76Date: Mon, 30 Nov 2009 20:05:32 GMT
77Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
78Supported: replaces
79Content-Length: 0
80
81
82--end msg--
83 13:51:59.468       endpoint  Response msg 200/OPTIONS/cseq=102 (tdta0x184e600) created
84 13:51:59.468   pjsua_core.c  TX 1188 bytes Response msg 200/OPTIONS/cseq=102 (tdta0x184e600) to UDP 173.8.19.148:5060:
85SIP/2.0 200 OK
86Via: SIP/2.0/UDP 173.8.19.148:5060;rport=5060;received=173.8.19.148;branch=z9hG4bK568a3c49
87Call-ID: 7a08c2d543456a5b22e920cf1ebef829@173.8.19.148
88From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as2b1f0eea
89To: <sip:4414@66.219.174.73>
90CSeq: 102 OPTIONS
91Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
92Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
93Supported: replaces, 100rel, timer, norefersub
94Allow-Events: presence, message-summary, refer
95User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
96Content-Type: application/sdp
97Content-Length:   445
98
99v=0
100o=- 3468595919 3468595919 IN IP4 10.127.1.99
101s=pjmedia
102c=IN IP4 10.127.1.99
103t=0 0
104m=audio 7000 RTP/AVP 103 102 104 113 3 0 8 9 101
105a=rtcp:7001 IN IP4 10.127.1.99
106a=rtpmap:103 speex/16000
107a=rtpmap:102 speex/8000
108a=rtpmap:104 speex/32000
109a=rtpmap:113 iLBC/8000
110a=fmtp:113 mode=30
111a=rtpmap:3 GSM/8000
112a=rtpmap:0 PCMU/8000
113a=rtpmap:8 PCMA/8000
114a=rtpmap:9 G722/8000
115a=sendrecv
116a=rtpmap:101 telephone-event/8000
117a=fmtp:101 0-15
118
119--end msg--
120 13:51:59.469  tdta0x184e600  Destroying txdata Response msg 200/OPTIONS/cseq=102 (tdta0x184e600)
121 13:51:59.530 sip_endpoint.c  Processing incoming message: Response msg 100/REGISTER/cseq=20722 (rdata0x182b664)
122 13:51:59.530   pjsua_core.c  RX 496 bytes Response msg 100/REGISTER/cseq=20722 (rdata0x182b664) from UDP 173.8.19.148:5060:
123SIP/2.0 100 Trying
124Via: SIP/2.0/UDP 10.127.1.99:5060;branch=z9hG4bKPj9129820D-75BA-404C-A8F4-0CD951872DF2;received=66.219.174.73;rport=5060
125From: <sip:4414@sip.example.com>;tag=839BF07A-93EE-47D4-8008-4F019ACEB257
126To: <sip:4414@sip.example.com>
127Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
128CSeq: 20722 REGISTER
129User-Agent: Asterisk PBX
130Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
131Supported: replaces
132Contact: <sip:4414@173.8.19.148>
133Content-Length: 0
134
135
136--end msg--
137 13:51:59.530   tsx0x182aa64  Incoming Response msg 100/REGISTER/cseq=20722 (rdata0x182b664) in state Calling
138 13:51:59.530   tsx0x182aa64  State changed from Calling to Proceeding, event=RX_MSG
139 13:51:59.543 sip_endpoint.c  Processing incoming message: Response msg 401/REGISTER/cseq=20722 (rdata0x182b664)
140 13:51:59.543   pjsua_core.c  RX 559 bytes Response msg 401/REGISTER/cseq=20722 (rdata0x182b664) from UDP 173.8.19.148:5060:
141SIP/2.0 401 Unauthorized
142Via: SIP/2.0/UDP 10.127.1.99:5060;branch=z9hG4bKPj9129820D-75BA-404C-A8F4-0CD951872DF2;received=66.219.174.73;rport=5060
143From: <sip:4414@sip.example.com>;tag=839BF07A-93EE-47D4-8008-4F019ACEB257
144To: <sip:4414@sip.example.com>;tag=as162917f2
145Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
146CSeq: 20722 REGISTER
147User-Agent: Asterisk PBX
148Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
149Supported: replaces
150WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7b9ec77c"
151Content-Length: 0
152
153
154--end msg--
155 13:51:59.543   tsx0x182aa64  Incoming Response msg 401/REGISTER/cseq=20722 (rdata0x182b664) in state Proceeding
156 13:51:59.543   tsx0x182aa64  State changed from Proceeding to Completed, event=RX_MSG
157 13:51:59.543   tsx0x184cc64  Transaction created for Request msg REGISTER/cseq=20723 (tdta0x182d400)
158 13:51:59.543   tsx0x184cc64  Sending Request msg REGISTER/cseq=20723 (tdta0x182d400) in state Null
159 13:51:59.543       endpoint  Request msg REGISTER/cseq=20723 (tdta0x182d400): skipping target resolution because address is already set
160 13:51:59.543   pjsua_core.c  TX 626 bytes Request msg REGISTER/cseq=20723 (tdta0x182d400) to UDP 173.8.19.148:5060:
161REGISTER sip:sip.example.com SIP/2.0
162Via: SIP/2.0/UDP 10.127.1.99:5060;rport;branch=z9hG4bKPjACB650C5-94DC-49C5-BF67-DAC5015EA1DC
163Max-Forwards: 70
164From: <sip:4414@sip.example.com>;tag=839BF07A-93EE-47D4-8008-4F019ACEB257
165To: <sip:4414@sip.example.com>
166Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
167CSeq: 20723 REGISTER
168User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
169Contact: <sip:4414@10.127.1.99:5060>
170Expires: 300
171Authorization: Digest username="4414", realm="asterisk", nonce="7b9ec77c", uri="sip:sip.example.com", response="764f37e116d58c46c186b642f6ae4214", algorithm=MD5
172Content-Length:  0
173
174
175--end msg--
176 13:51:59.545   tsx0x184cc64  State changed from Null to Calling, event=TX_MSG
177 13:51:59.628 sip_endpoint.c  Processing incoming message: Response msg 100/REGISTER/cseq=20723 (rdata0x182b664)
178 13:51:59.628   pjsua_core.c  RX 496 bytes Response msg 100/REGISTER/cseq=20723 (rdata0x182b664) from UDP 173.8.19.148:5060:
179SIP/2.0 100 Trying
180Via: SIP/2.0/UDP 10.127.1.99:5060;branch=z9hG4bKPjACB650C5-94DC-49C5-BF67-DAC5015EA1DC;received=66.219.174.73;rport=5060
181From: <sip:4414@sip.example.com>;tag=839BF07A-93EE-47D4-8008-4F019ACEB257
182To: <sip:4414@sip.example.com>
183Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
184CSeq: 20723 REGISTER
185User-Agent: Asterisk PBX
186Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
187Supported: replaces
188Contact: <sip:4414@173.8.19.148>
189Content-Length: 0
190
191
192--end msg--
193 13:51:59.628   tsx0x184cc64  Incoming Response msg 100/REGISTER/cseq=20723 (rdata0x182b664) in state Calling
194 13:51:59.628   tsx0x184cc64  State changed from Calling to Proceeding, event=RX_MSG
195 13:51:59.636 sip_endpoint.c  Processing incoming message: Response msg 200/REGISTER/cseq=20723 (rdata0x182b664)
196 13:51:59.636   pjsua_core.c  RX 574 bytes Response msg 200/REGISTER/cseq=20723 (rdata0x182b664) from UDP 173.8.19.148:5060:
197SIP/2.0 200 OK
198Via: SIP/2.0/UDP 10.127.1.99:5060;branch=z9hG4bKPjACB650C5-94DC-49C5-BF67-DAC5015EA1DC;received=66.219.174.73;rport=5060
199From: <sip:4414@sip.example.com>;tag=839BF07A-93EE-47D4-8008-4F019ACEB257
200To: <sip:4414@sip.example.com>;tag=as162917f2
201Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
202CSeq: 20723 REGISTER
203User-Agent: Asterisk PBX
204Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
205Supported: replaces
206Expires: 300
207Contact: <sip:4414@10.127.1.99:5060>;expires=300
208Date: Mon, 30 Nov 2009 20:05:36 GMT
209Content-Length: 0
210
211
212--end msg--
213 13:51:59.636   tsx0x184cc64  Incoming Response msg 200/REGISTER/cseq=20723 (rdata0x182b664) in state Proceeding
214 13:51:59.636   tsx0x184cc64  State changed from Proceeding to Completed, event=RX_MSG
215 13:51:59.636    pjsua_acc.c  IP address change detected for account 2 (10.127.1.99:5060 --> 66.219.174.73:5060). Updating registration..
216 13:51:59.636       endpoint  Request msg REGISTER/cseq=20723 (tdta0x184e600) created.
217 13:51:59.636   tsx0x1832464  Transaction created for Request msg REGISTER/cseq=20724 (tdta0x184e600)
218 13:51:59.636   tsx0x1832464  Sending Request msg REGISTER/cseq=20724 (tdta0x184e600) in state Null
219 13:51:59.636  sip_resolve.c  DNS resolver not available, target 'sip.example.com:0' type=Unspecified will be resolved with gethostbyname()
220 13:51:59.637  sip_resolve.c  Target 'sip.example.com:0' type=Unspecified resolved to '173.8.19.148:5060' type=UDP (UDP transport)
221 13:51:59.637   pjsua_core.c  TX 458 bytes Request msg REGISTER/cseq=20724 (tdta0x184e600) to UDP 173.8.19.148:5060:
222REGISTER sip:sip.example.com SIP/2.0
223Via: SIP/2.0/UDP 10.127.1.99:5060;rport;branch=z9hG4bKPj09C90333-6431-4828-A85C-E98C601E7EE8
224Max-Forwards: 70
225From: <sip:4414@sip.example.com>;tag=176FAB28-04BC-47DE-B0BF-3621A4D4DD06
226To: <sip:4414@sip.example.com>
227Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
228CSeq: 20724 REGISTER
229User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
230Contact: <sip:4414@10.127.1.99:5060>
231Expires: 0
232Content-Length:  0
233
234
235--end msg--
236 13:51:59.637   tsx0x1832464  State changed from Null to Calling, event=TX_MSG
237 13:51:59.637    pjsua_acc.c  Unregistration sent
238 13:51:59.637       endpoint  Request msg REGISTER/cseq=10541 (tdta0x1851200) created.
239 13:51:59.637   tsx0x1852264  Transaction created for Request msg REGISTER/cseq=10542 (tdta0x1851200)
240 13:51:59.637   tsx0x1852264  Sending Request msg REGISTER/cseq=10542 (tdta0x1851200) in state Null
241 13:51:59.637  sip_resolve.c  DNS resolver not available, target 'sip.example.com:0' type=Unspecified will be resolved with gethostbyname()
242 13:51:59.638  sip_resolve.c  Target 'sip.example.com:0' type=Unspecified resolved to '173.8.19.148:5060' type=UDP (UDP transport)
243 13:51:59.638   pjsua_core.c  TX 478 bytes Request msg REGISTER/cseq=10542 (tdta0x1851200) to UDP 173.8.19.148:5060:
244REGISTER sip:sip.example.com SIP/2.0
245Via: SIP/2.0/UDP 66.219.174.73:5060;rport;branch=z9hG4bKPjD761F86B-AB0F-4D8D-B60F-A88FD7451411
246Max-Forwards: 70
247From: <sip:4414@sip.example.com>;tag=A92223E5-41C4-432F-8607-021E6F4E5545
248To: <sip:4414@sip.example.com>
249Call-ID: A26ED88D-5038-4611-9079-6D79B6D67AC7
250CSeq: 10542 REGISTER
251User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
252Contact: <sip:4414@66.219.174.73:5060;transport=UDP>
253Expires: 300
254Content-Length:  0
255
256
257--end msg--
258 13:51:59.639   tsx0x1852264  State changed from Null to Calling, event=TX_MSG
259 13:51:59.639    pjsua_acc.c  Registration sent
260 13:51:59.718 sip_endpoint.c  Processing incoming message: Response msg 100/REGISTER/cseq=20724 (rdata0x182b664)
261 13:51:59.718   pjsua_core.c  RX 496 bytes Response msg 100/REGISTER/cseq=20724 (rdata0x182b664) from UDP 173.8.19.148:5060:
262SIP/2.0 100 Trying
263Via: SIP/2.0/UDP 10.127.1.99:5060;branch=z9hG4bKPj09C90333-6431-4828-A85C-E98C601E7EE8;received=66.219.174.73;rport=5060
264From: <sip:4414@sip.example.com>;tag=176FAB28-04BC-47DE-B0BF-3621A4D4DD06
265To: <sip:4414@sip.example.com>
266Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
267CSeq: 20724 REGISTER
268User-Agent: Asterisk PBX
269Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
270Supported: replaces
271Contact: <sip:4414@173.8.19.148>
272Content-Length: 0
273
274
275--end msg--
276 13:51:59.718   tsx0x1832464  Incoming Response msg 100/REGISTER/cseq=20724 (rdata0x182b664) in state Calling
277 13:51:59.718   tsx0x1832464  State changed from Calling to Proceeding, event=RX_MSG
278 13:51:59.741 sip_endpoint.c  Processing incoming message: Response msg 401/REGISTER/cseq=20724 (rdata0x182b664)
279 13:51:59.741   pjsua_core.c  RX 559 bytes Response msg 401/REGISTER/cseq=20724 (rdata0x182b664) from UDP 173.8.19.148:5060:
280SIP/2.0 401 Unauthorized
281Via: SIP/2.0/UDP 10.127.1.99:5060;branch=z9hG4bKPj09C90333-6431-4828-A85C-E98C601E7EE8;received=66.219.174.73;rport=5060
282From: <sip:4414@sip.example.com>;tag=176FAB28-04BC-47DE-B0BF-3621A4D4DD06
283To: <sip:4414@sip.example.com>;tag=as162917f2
284Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
285CSeq: 20724 REGISTER
286User-Agent: Asterisk PBX
287Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
288Supported: replaces
289WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="3b0ae503"
290Content-Length: 0
291
292
293--end msg--
294 13:51:59.742   tsx0x1832464  Incoming Response msg 401/REGISTER/cseq=20724 (rdata0x182b664) in state Proceeding
295 13:51:59.742   tsx0x1832464  State changed from Proceeding to Completed, event=RX_MSG
296 13:51:59.742   tsx0x1853a64  Transaction created for Request msg REGISTER/cseq=20725 (tdta0x184e600)
297 13:51:59.742   tsx0x1853a64  Sending Request msg REGISTER/cseq=20725 (tdta0x184e600) in state Null
298 13:51:59.742       endpoint  Request msg REGISTER/cseq=20725 (tdta0x184e600): skipping target resolution because address is already set
299 13:51:59.742   pjsua_core.c  TX 626 bytes Request msg REGISTER/cseq=20725 (tdta0x184e600) to UDP 173.8.19.148:5060:
300REGISTER sip:sip.example.com SIP/2.0
301Via: SIP/2.0/UDP 66.219.174.73:5060;rport;branch=z9hG4bKPj9080803E-6446-4AC4-AAFF-4A9C62864BCE
302Max-Forwards: 70
303From: <sip:4414@sip.example.com>;tag=176FAB28-04BC-47DE-B0BF-3621A4D4DD06
304To: <sip:4414@sip.example.com>
305Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
306CSeq: 20725 REGISTER
307User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
308Contact: <sip:4414@10.127.1.99:5060>
309Expires: 0
310Authorization: Digest username="4414", realm="asterisk", nonce="3b0ae503", uri="sip:sip.example.com", response="c93d5de22b04304d1c7c9debdd44fcae", algorithm=MD5
311Content-Length:  0
312
313
314--end msg--
315 13:51:59.743   tsx0x1853a64  State changed from Null to Calling, event=TX_MSG
316 13:51:59.755 sip_endpoint.c  Processing incoming message: Response msg 100/REGISTER/cseq=10542 (rdata0x182b664)
317 13:51:59.755   pjsua_core.c  RX 498 bytes Response msg 100/REGISTER/cseq=10542 (rdata0x182b664) from UDP 173.8.19.148:5060:
318SIP/2.0 100 Trying
319Via: SIP/2.0/UDP 66.219.174.73:5060;branch=z9hG4bKPjD761F86B-AB0F-4D8D-B60F-A88FD7451411;received=66.219.174.73;rport=5060
320From: <sip:4414@sip.example.com>;tag=A92223E5-41C4-432F-8607-021E6F4E5545
321To: <sip:4414@sip.example.com>
322Call-ID: A26ED88D-5038-4611-9079-6D79B6D67AC7
323CSeq: 10542 REGISTER
324User-Agent: Asterisk PBX
325Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
326Supported: replaces
327Contact: <sip:4414@173.8.19.148>
328Content-Length: 0
329
330
331--end msg--
332 13:51:59.755   tsx0x1852264  Incoming Response msg 100/REGISTER/cseq=10542 (rdata0x182b664) in state Calling
333 13:51:59.755   tsx0x1852264  State changed from Calling to Proceeding, event=RX_MSG
334 13:51:59.755 sip_endpoint.c  Processing incoming message: Response msg 401/REGISTER/cseq=10542 (rdata0x182b664)
335 13:51:59.755   pjsua_core.c  RX 561 bytes Response msg 401/REGISTER/cseq=10542 (rdata0x182b664) from UDP 173.8.19.148:5060:
336SIP/2.0 401 Unauthorized
337Via: SIP/2.0/UDP 66.219.174.73:5060;branch=z9hG4bKPjD761F86B-AB0F-4D8D-B60F-A88FD7451411;received=66.219.174.73;rport=5060
338From: <sip:4414@sip.example.com>;tag=A92223E5-41C4-432F-8607-021E6F4E5545
339To: <sip:4414@sip.example.com>;tag=as5f1b651c
340Call-ID: A26ED88D-5038-4611-9079-6D79B6D67AC7
341CSeq: 10542 REGISTER
342User-Agent: Asterisk PBX
343Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
344Supported: replaces
345WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="45b32568"
346Content-Length: 0
347
348
349--end msg--
350 13:51:59.756   tsx0x1852264  Incoming Response msg 401/REGISTER/cseq=10542 (rdata0x182b664) in state Proceeding
351 13:51:59.756   tsx0x1852264  State changed from Proceeding to Completed, event=RX_MSG
352 13:51:59.756   tsx0x1854264  Transaction created for Request msg REGISTER/cseq=10543 (tdta0x1851200)
353 13:51:59.756   tsx0x1854264  Sending Request msg REGISTER/cseq=10543 (tdta0x1851200) in state Null
354 13:51:59.756       endpoint  Request msg REGISTER/cseq=10543 (tdta0x1851200): skipping target resolution because address is already set
355 13:51:59.756   pjsua_core.c  TX 644 bytes Request msg REGISTER/cseq=10543 (tdta0x1851200) to UDP 173.8.19.148:5060:
356REGISTER sip:sip.example.com SIP/2.0
357Via: SIP/2.0/UDP 66.219.174.73:5060;rport;branch=z9hG4bKPj4DF6E5BA-2B4D-4514-B296-C04172DB98C1
358Max-Forwards: 70
359From: <sip:4414@sip.example.com>;tag=A92223E5-41C4-432F-8607-021E6F4E5545
360To: <sip:4414@sip.example.com>
361Call-ID: A26ED88D-5038-4611-9079-6D79B6D67AC7
362CSeq: 10543 REGISTER
363User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
364Contact: <sip:4414@66.219.174.73:5060;transport=UDP>
365Expires: 300
366Authorization: Digest username="4414", realm="asterisk", nonce="45b32568", uri="sip:sip.example.com", response="9d376d7aeb00a86d1576d5ba58bb27b0", algorithm=MD5
367Content-Length:  0
368
369
370--end msg--
371 13:51:59.761   tsx0x1854264  State changed from Null to Calling, event=TX_MSG
372 13:51:59.838 sip_endpoint.c  Processing incoming message: Response msg 100/REGISTER/cseq=20725 (rdata0x182b664)
373 13:51:59.838   pjsua_core.c  RX 498 bytes Response msg 100/REGISTER/cseq=20725 (rdata0x182b664) from UDP 173.8.19.148:5060:
374SIP/2.0 100 Trying
375Via: SIP/2.0/UDP 66.219.174.73:5060;branch=z9hG4bKPj9080803E-6446-4AC4-AAFF-4A9C62864BCE;received=66.219.174.73;rport=5060
376From: <sip:4414@sip.example.com>;tag=176FAB28-04BC-47DE-B0BF-3621A4D4DD06
377To: <sip:4414@sip.example.com>
378Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
379CSeq: 20725 REGISTER
380User-Agent: Asterisk PBX
381Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
382Supported: replaces
383Contact: <sip:4414@173.8.19.148>
384Content-Length: 0
385
386
387--end msg--
388 13:51:59.839   tsx0x1853a64  Incoming Response msg 100/REGISTER/cseq=20725 (rdata0x182b664) in state Calling
389 13:51:59.839   tsx0x1853a64  State changed from Calling to Proceeding, event=RX_MSG
390 13:51:59.844 sip_endpoint.c  Processing incoming message: Response msg 200/REGISTER/cseq=20725 (rdata0x182b664)
391 13:51:59.844   pjsua_core.c  RX 572 bytes Response msg 200/REGISTER/cseq=20725 (rdata0x182b664) from UDP 173.8.19.148:5060:
392SIP/2.0 200 OK
393Via: SIP/2.0/UDP 66.219.174.73:5060;branch=z9hG4bKPj9080803E-6446-4AC4-AAFF-4A9C62864BCE;received=66.219.174.73;rport=5060
394From: <sip:4414@sip.example.com>;tag=176FAB28-04BC-47DE-B0BF-3621A4D4DD06
395To: <sip:4414@sip.example.com>;tag=as162917f2
396Call-ID: 7705D8EA-1E47-4A25-9D45-3C90A3A92121
397CSeq: 20725 REGISTER
398User-Agent: Asterisk PBX
399Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
400Supported: replaces
401Expires: 300
402Contact: <sip:4414@173.8.19.148>;expires=300
403Date: Mon, 30 Nov 2009 20:05:37 GMT
404Content-Length: 0
405
406
407--end msg--
408 13:51:59.844   tsx0x1853a64  Incoming Response msg 200/REGISTER/cseq=20725 (rdata0x182b664) in state Proceeding
409 13:51:59.844   tsx0x1853a64  State changed from Proceeding to Completed, event=RX_MSG
410 13:51:59.849 sip_endpoint.c  Processing incoming message: Response msg 100/REGISTER/cseq=10543 (rdata0x182b664)
411 13:51:59.849   pjsua_core.c  RX 498 bytes Response msg 100/REGISTER/cseq=10543 (rdata0x182b664) from UDP 173.8.19.148:5060:
412SIP/2.0 100 Trying
413Via: SIP/2.0/UDP 66.219.174.73:5060;branch=z9hG4bKPj4DF6E5BA-2B4D-4514-B296-C04172DB98C1;received=66.219.174.73;rport=5060
414From: <sip:4414@sip.example.com>;tag=A92223E5-41C4-432F-8607-021E6F4E5545
415To: <sip:4414@sip.example.com>
416Call-ID: A26ED88D-5038-4611-9079-6D79B6D67AC7
417CSeq: 10543 REGISTER
418User-Agent: Asterisk PBX
419Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
420Supported: replaces
421Contact: <sip:4414@173.8.19.148>
422Content-Length: 0
423
424
425--end msg--
426 13:51:59.850   tsx0x1854264  Incoming Response msg 100/REGISTER/cseq=10543 (rdata0x182b664) in state Calling
427 13:51:59.850   tsx0x1854264  State changed from Calling to Proceeding, event=RX_MSG
428 13:51:59.853 sip_endpoint.c  Processing incoming message: Request msg OPTIONS/cseq=102 (rdata0x182b664)
429 13:51:59.853   pjsua_core.c  RX 535 bytes Request msg OPTIONS/cseq=102 (rdata0x182b664) from UDP 173.8.19.148:5060:
430OPTIONS sip:4414@66.219.174.73:5060;transport=UDP SIP/2.0
431Via: SIP/2.0/UDP 173.8.19.148:5060;branch=z9hG4bK4a5f7940;rport
432From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as5015fc6b
433To: <sip:4414@66.219.174.73:5060;transport=UDP>
434Contact: <sip:Unknown@173.8.19.148>
435Call-ID: 6c2e04cb05fa73f517d318c751ec5668@173.8.19.148
436CSeq: 102 OPTIONS
437User-Agent: Asterisk PBX
438Max-Forwards: 70
439Date: Mon, 30 Nov 2009 20:05:37 GMT
440Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
441Supported: replaces
442Content-Length: 0
443
444
445--end msg--
446 13:51:59.855       endpoint  Response msg 200/OPTIONS/cseq=102 (tdta0x1854a00) created
447 13:51:59.855   pjsua_core.c  TX 1188 bytes Response msg 200/OPTIONS/cseq=102 (tdta0x1854a00) to UDP 173.8.19.148:5060:
448SIP/2.0 200 OK
449Via: SIP/2.0/UDP 173.8.19.148:5060;rport=5060;received=173.8.19.148;branch=z9hG4bK4a5f7940
450Call-ID: 6c2e04cb05fa73f517d318c751ec5668@173.8.19.148
451From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as5015fc6b
452To: <sip:4414@66.219.174.73>
453CSeq: 102 OPTIONS
454Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
455Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
456Supported: replaces, 100rel, timer, norefersub
457Allow-Events: presence, message-summary, refer
458User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
459Content-Type: application/sdp
460Content-Length:   445
461
462v=0
463o=- 3468595919 3468595919 IN IP4 10.127.1.99
464s=pjmedia
465c=IN IP4 10.127.1.99
466t=0 0
467m=audio 7000 RTP/AVP 103 102 104 113 3 0 8 9 101
468a=rtcp:7001 IN IP4 10.127.1.99
469a=rtpmap:103 speex/16000
470a=rtpmap:102 speex/8000
471a=rtpmap:104 speex/32000
472a=rtpmap:113 iLBC/8000
473a=fmtp:113 mode=30
474a=rtpmap:3 GSM/8000
475a=rtpmap:0 PCMU/8000
476a=rtpmap:8 PCMA/8000
477a=rtpmap:9 G722/8000
478a=sendrecv
479a=rtpmap:101 telephone-event/8000
480a=fmtp:101 0-15
481
482--end msg--
483 13:51:59.856  tdta0x1854a00  Destroying txdata Response msg 200/OPTIONS/cseq=102 (tdta0x1854a00)
484 13:51:59.859 sip_endpoint.c  Processing incoming message: Response msg 200/REGISTER/cseq=10543 (rdata0x182b664)
485 13:51:59.859   pjsua_core.c  RX 592 bytes Response msg 200/REGISTER/cseq=10543 (rdata0x182b664) from UDP 173.8.19.148:5060:
486SIP/2.0 200 OK
487Via: SIP/2.0/UDP 66.219.174.73:5060;branch=z9hG4bKPj4DF6E5BA-2B4D-4514-B296-C04172DB98C1;received=66.219.174.73;rport=5060
488From: <sip:4414@sip.example.com>;tag=A92223E5-41C4-432F-8607-021E6F4E5545
489To: <sip:4414@sip.example.com>;tag=as5f1b651c
490Call-ID: A26ED88D-5038-4611-9079-6D79B6D67AC7
491CSeq: 10543 REGISTER
492User-Agent: Asterisk PBX
493Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
494Supported: replaces
495Expires: 300
496Contact: <sip:4414@66.219.174.73:5060;transport=UDP>;expires=300
497Date: Mon, 30 Nov 2009 20:05:37 GMT
498Content-Length: 0
499
500
501--end msg--
502 13:51:59.860   tsx0x1854264  Incoming Response msg 200/REGISTER/cseq=10543 (rdata0x182b664) in state Proceeding
503 13:51:59.860   tsx0x1854264  State changed from Proceeding to Completed, event=RX_MSG
504 13:51:59.860    pjsua_acc.c  sip:4414@sip.example.com: registration success, status=200 (OK), will re-register in 300 seconds
505 13:51:59.860    pjsua_acc.c  Keep-alive timer started for acc 2, destination:173.8.19.148:5060, interval:15s
506 13:52:04.548   tsx0x182aa64  Timeout timer event
507 13:52:04.548   tsx0x182aa64  State changed from Completed to Terminated, event=TIMER
508 13:52:04.548   tsx0x182aa64  Timeout timer event
509 13:52:04.548   tsx0x182aa64  State changed from Terminated to Destroyed, event=TIMER
510 13:52:04.548   tsx0x182aa64  Transaction destroyed!
511 13:52:04.639   tsx0x184cc64  Timeout timer event
512 13:52:04.639   tsx0x184cc64  State changed from Completed to Terminated, event=TIMER
513 13:52:04.639   tsx0x184cc64  Timeout timer event
514 13:52:04.639   tsx0x184cc64  State changed from Terminated to Destroyed, event=TIMER
515 13:52:04.639  tdta0x182d400  Destroying txdata Request msg REGISTER/cseq=20723 (tdta0x182d400)
516 13:52:04.639   tsx0x184cc64  Transaction destroyed!
517 13:52:04.750   tsx0x1832464  Timeout timer event
518 13:52:04.750   tsx0x1832464  State changed from Completed to Terminated, event=TIMER
519 13:52:04.750   tsx0x1832464  Timeout timer event
520 13:52:04.750   tsx0x1832464  State changed from Terminated to Destroyed, event=TIMER
521 13:52:04.750   tsx0x1832464  Transaction destroyed!
522 13:52:04.770   tsx0x1852264  Timeout timer event
523 13:52:04.770   tsx0x1852264  State changed from Completed to Terminated, event=TIMER
524 13:52:04.770   tsx0x1852264  Timeout timer event
525 13:52:04.770   tsx0x1852264  State changed from Terminated to Destroyed, event=TIMER
526 13:52:04.770   tsx0x1852264  Transaction destroyed!
527 13:52:04.851   tsx0x1853a64  Timeout timer event
528 13:52:04.851   tsx0x1853a64  State changed from Completed to Terminated, event=TIMER
529 13:52:04.851   tsx0x1853a64  Timeout timer event
530 13:52:04.851   tsx0x1853a64  State changed from Terminated to Destroyed, event=TIMER
531 13:52:04.851  tdta0x184e600  Destroying txdata Request msg REGISTER/cseq=20725 (tdta0x184e600)
532 13:52:04.851   tsx0x1853a64  Transaction destroyed!
533 13:52:04.861   tsx0x1854264  Timeout timer event
534 13:52:04.861   tsx0x1854264  State changed from Completed to Terminated, event=TIMER
535 13:52:04.861   tsx0x1854264  Timeout timer event
536 13:52:04.861   tsx0x1854264  State changed from Terminated to Destroyed, event=TIMER
537 13:52:04.861  tdta0x1851200  Destroying txdata Request msg REGISTER/cseq=10543 (tdta0x1851200)
538 13:52:04.861   tsx0x1854264  Transaction destroyed!
539 13:52:08.563 sip_endpoint.c  Processing incoming message: Request msg NOTIFY/cseq=102 (rdata0x182b664)
540 13:52:08.563   pjsua_core.c  RX 570 bytes Request msg NOTIFY/cseq=102 (rdata0x182b664) from UDP 173.8.19.148:5060:
541NOTIFY sip:4414@66.219.174.73:5060;transport=UDP SIP/2.0
542Via: SIP/2.0/UDP 173.8.19.148:5060;branch=z9hG4bK1f9c067f;rport
543From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as384a6eed
544To: <sip:4414@66.219.174.73:5060;transport=UDP>
545Contact: <sip:Unknown@173.8.19.148>
546Call-ID: 5016fcaa35e173d35a6a287148031607@173.8.19.148
547CSeq: 102 NOTIFY
548User-Agent: Asterisk PBX
549Max-Forwards: 70
550Event: message-summary
551Content-Type: application/simple-message-summary
552Content-Length: 88
553
554Messages-Waiting: yes
555Message-Account: sip:*86@173.8.19.148
556Voice-Message: 6/0 (0/0)
557
558--end msg--
559 13:52:08.563       endpoint  Response msg 200/NOTIFY/cseq=102 (tdta0x1854a00) created
560 13:52:08.563   tsx0x1854264  Transaction created for Request msg NOTIFY/cseq=102 (rdata0x182b664)
561 13:52:08.563   tsx0x1854264  Incoming Request msg NOTIFY/cseq=102 (rdata0x182b664) in state Null
562 13:52:08.563   tsx0x1854264  State changed from Null to Trying, event=RX_MSG
563 13:52:08.563   tsx0x1854264  Sending Response msg 200/NOTIFY/cseq=102 (tdta0x1854a00) in state Trying
564 13:52:08.563   pjsua_core.c  TX 293 bytes Response msg 200/NOTIFY/cseq=102 (tdta0x1854a00) to UDP 173.8.19.148:5060:
565SIP/2.0 200 OK
566Via: SIP/2.0/UDP 173.8.19.148:5060;rport=5060;received=173.8.19.148;branch=z9hG4bK1f9c067f
567Call-ID: 5016fcaa35e173d35a6a287148031607@173.8.19.148
568From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as384a6eed
569To: <sip:4414@66.219.174.73>
570CSeq: 102 NOTIFY
571Content-Length:  0
572
573
574--end msg--
575 13:52:08.563   tsx0x1854264  State changed from Trying to Completed, event=TX_MSG
576 13:52:08.563    pjsua_app.c  Received MWI for acc 2:
577 13:52:08.563    pjsua_app.c   Content-Type: application/simple-message-summary
578 13:52:08.563    pjsua_app.c   Body:
579Messages-Waiting: yes
580Message-Account: sip:*86@173.8.19.148
581Voice-Message: 6/0 (0/0)
582
583 13:52:14.862    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
584 13:52:14.862  tdta0x1855a00  Destroying txdata raw
585 13:52:29.864    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
586 13:52:29.864  tdta0x1855a00  Destroying txdata raw
587 13:52:40.571   tsx0x1854264  Timeout timer event
588 13:52:40.571   tsx0x1854264  State changed from Completed to Terminated, event=TIMER
589 13:52:40.571   tsx0x1854264  Timeout timer event
590 13:52:40.571   tsx0x1854264  State changed from Terminated to Destroyed, event=TIMER
591 13:52:40.571  tdta0x1854a00  Destroying txdata Response msg 200/NOTIFY/cseq=102 (tdta0x1854a00)
592 13:52:40.571   tsx0x1854264  Transaction destroyed!
593 13:52:44.871    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
594 13:52:44.871  tdta0x1854a00  Destroying txdata raw
595 13:52:59.878    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
596 13:52:59.878  tdta0x1854a00  Destroying txdata raw
597 13:52:59.938 sip_endpoint.c  Processing incoming message: Request msg OPTIONS/cseq=102 (rdata0x182b664)
598 13:52:59.938   pjsua_core.c  RX 535 bytes Request msg OPTIONS/cseq=102 (rdata0x182b664) from UDP 173.8.19.148:5060:
599OPTIONS sip:4414@66.219.174.73:5060;transport=UDP SIP/2.0
600Via: SIP/2.0/UDP 173.8.19.148:5060;branch=z9hG4bK5ec1d028;rport
601From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as4291dcf9
602To: <sip:4414@66.219.174.73:5060;transport=UDP>
603Contact: <sip:Unknown@173.8.19.148>
604Call-ID: 69f0bc3119e0ebd3607fe77112917f5b@173.8.19.148
605CSeq: 102 OPTIONS
606User-Agent: Asterisk PBX
607Max-Forwards: 70
608Date: Mon, 30 Nov 2009 20:06:37 GMT
609Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
610Supported: replaces
611Content-Length: 0
612
613
614--end msg--
615 13:52:59.939       endpoint  Response msg 200/OPTIONS/cseq=102 (tdta0x1855a00) created
616 13:52:59.939   pjsua_core.c  TX 1188 bytes Response msg 200/OPTIONS/cseq=102 (tdta0x1855a00) to UDP 173.8.19.148:5060:
617SIP/2.0 200 OK
618Via: SIP/2.0/UDP 173.8.19.148:5060;rport=5060;received=173.8.19.148;branch=z9hG4bK5ec1d028
619Call-ID: 69f0bc3119e0ebd3607fe77112917f5b@173.8.19.148
620From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as4291dcf9
621To: <sip:4414@66.219.174.73>
622CSeq: 102 OPTIONS
623Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
624Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
625Supported: replaces, 100rel, timer, norefersub
626Allow-Events: presence, message-summary, refer
627User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
628Content-Type: application/sdp
629Content-Length:   445
630
631v=0
632o=- 3468595979 3468595979 IN IP4 10.127.1.99
633s=pjmedia
634c=IN IP4 10.127.1.99
635t=0 0
636m=audio 7000 RTP/AVP 103 102 104 113 3 0 8 9 101
637a=rtcp:7001 IN IP4 10.127.1.99
638a=rtpmap:103 speex/16000
639a=rtpmap:102 speex/8000
640a=rtpmap:104 speex/32000
641a=rtpmap:113 iLBC/8000
642a=fmtp:113 mode=30
643a=rtpmap:3 GSM/8000
644a=rtpmap:0 PCMU/8000
645a=rtpmap:8 PCMA/8000
646a=rtpmap:9 G722/8000
647a=sendrecv
648a=rtpmap:101 telephone-event/8000
649a=fmtp:101 0-15
650
651--end msg--
652 13:52:59.940  tdta0x1855a00  Destroying txdata Response msg 200/OPTIONS/cseq=102 (tdta0x1855a00)
653 13:53:10.153  pjsua_media.c  Opening sound device PCM@16000/1/20ms
654 13:53:10.882       pa_dev.c  Opened device Built-in Microphone(Core Audio)/Built-in Output(Core Audio) for recording and playback, sample rate=16000, ch=1, bits=16, 320 samples per frame, input latency=0 ms, output latency=0 ms
655 13:53:10.882     ec0x4c2880  Creating AEC
656 13:53:10.883     ec0x4c2880  AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=20 ms
657 13:53:10.883       pa_dev.c  Starting Built-in Microphone stream..
658 13:53:10.884       pa_dev.c  Done, status=0
659 13:53:10.884   pjsua_call.c  Making call with acc #2 to sip:3304128820@sip.example.com
660 13:53:10.884   dlg0x187e064  UAC dialog created
661 13:53:10.884  pjsua_media.c  Media index 0 selected for call 0
662 13:53:10.884        _krtp.c  transport_media_create: offerer=1 use=1
663 13:53:10.884        _krtp.c  media_create krtp: 0x182b264 handle: 10000
664 13:53:10.891       pa_dev.c  Player thread started
665 13:53:10.905     ec0x4c2880  Latency bufferring complete
666 13:53:10.906       pa_dev.c  Recorder thread started
667 13:53:11.190        _krtp.c  TC Card Connected
668 13:53:11.312        _krtp.c  TC Profiles found: 1
669 13:53:11.352        _krtp.c  TCB Session Created
670 13:53:11.353        _krtp.c  TC Session Created
671 13:53:11.353   dlg0x187e064  Module mod-invite added as dialog usage, data=0x1885414
672 13:53:11.353   dlg0x187e064  Session count inc to 3 by mod-invite
673 13:53:11.353   dlg0x187e064  Module mod-100rel added as dialog usage, data=0x187e7f4
674 13:53:11.353   dlg0x187e064  100rel module attached
675 13:53:11.353   inv0x187e064  UAC invite session created for dialog dlg0x187e064
676 13:53:11.353       endpoint  Request msg INVITE/cseq=4313 (tdta0x1886400) created.
677 13:53:11.353   inv0x187e064  Sending Request msg INVITE/cseq=4313 (tdta0x1886400)
678 13:53:11.353   dlg0x187e064  Sending Request msg INVITE/cseq=4313 (tdta0x1886400)
679 13:53:11.353   tsx0x1888464  Transaction created for Request msg INVITE/cseq=4312 (tdta0x1886400)
680 13:53:11.353   tsx0x1888464  Sending Request msg INVITE/cseq=4312 (tdta0x1886400) in state Null
681 13:53:11.353  sip_resolve.c  DNS resolver not available, target 'sip.example.com:0' type=Unspecified will be resolved with gethostbyname()
682 13:53:11.353  sip_resolve.c  Target 'sip.example.com:0' type=Unspecified resolved to '173.8.19.148:5060' type=UDP (UDP transport)
683 13:53:11.354   pjsua_core.c  TX 1137 bytes Request msg INVITE/cseq=4312 (tdta0x1886400) to UDP 173.8.19.148:5060:
684INVITE sip:3304128820@sip.example.com SIP/2.0
685Via: SIP/2.0/UDP 66.219.174.73:5060;rport;branch=z9hG4bKPj5C9AD436-16CC-4DFE-9C53-21CA51F84ECD
686Max-Forwards: 70
687From: sip:4414@sip.example.com;tag=D1F45773-0B5E-4155-B6C0-AF7E0DBDA1B3
688To: sip:3304128820@sip.example.com
689Contact: <sip:4414@66.219.174.73:5060;transport=UDP>
690Call-ID: 3B1E22FB-3601-4D79-82F1-68C22970B95C
691CSeq: 4312 INVITE
692Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
693Supported: replaces, 100rel, timer, norefersub
694Session-Expires: 1800
695Min-SE: 90
696User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
697Content-Type: application/sdp
698Content-Length:   456
699
700v=0
701o=- 3468595991 3468595991 IN IP4 10.127.1.99
702s=pjmedia
703c=IN IP4 10.127.1.99
704t=0 0
705a=X-nat:0
706m=audio 7000 RTP/AVP 103 102 104 113 3 0 8 9 101
707a=rtcp:7001 IN IP4 10.127.1.99
708a=rtpmap:103 speex/16000
709a=rtpmap:102 speex/8000
710a=rtpmap:104 speex/32000
711a=rtpmap:113 iLBC/8000
712a=fmtp:113 mode=30
713a=rtpmap:3 GSM/8000
714a=rtpmap:0 PCMU/8000
715a=rtpmap:8 PCMA/8000
716a=rtpmap:9 G722/8000
717a=sendrecv
718a=rtpmap:101 telephone-event/8000
719a=fmtp:101 0-15
720
721--end msg--
722 13:53:11.355   tsx0x1888464  State changed from Null to Calling, event=TX_MSG
723 13:53:11.355   dlg0x187e064  Transaction tsx0x1888464 state changed to Calling
724 13:53:11.355    pjsua_app.c  Call 0 state changed to CALLING
725 13:53:11.453 sip_endpoint.c  Processing incoming message: Response msg 407/INVITE/cseq=4312 (rdata0x182b664)
726 13:53:11.453   pjsua_core.c  RX 579 bytes Response msg 407/INVITE/cseq=4312 (rdata0x182b664) from UDP 173.8.19.148:5060:
727SIP/2.0 407 Proxy Authentication Required
728Via: SIP/2.0/UDP 66.219.174.73:5060;branch=z9hG4bKPj5C9AD436-16CC-4DFE-9C53-21CA51F84ECD;received=66.219.174.73;rport=5060
729From: sip:4414@sip.example.com;tag=D1F45773-0B5E-4155-B6C0-AF7E0DBDA1B3
730To: sip:3304128820@sip.example.com;tag=as344909d4
731Call-ID: 3B1E22FB-3601-4D79-82F1-68C22970B95C
732CSeq: 4312 INVITE
733User-Agent: Asterisk PBX
734Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
735Supported: replaces
736Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0f1f398a"
737Content-Length: 0
738
739
740--end msg--
741 13:53:11.453   tsx0x1888464  Incoming Response msg 407/INVITE/cseq=4312 (rdata0x182b664) in state Calling
742 13:53:11.453       endpoint  Request msg ACK/cseq=4312 (tdta0x1889c00) created.
743 13:53:11.453   pjsua_core.c  TX 379 bytes Request msg ACK/cseq=4312 (tdta0x1889c00) to UDP 173.8.19.148:5060:
744ACK sip:3304128820@sip.example.com SIP/2.0
745Via: SIP/2.0/UDP 66.219.174.73:5060;rport;branch=z9hG4bKPj5C9AD436-16CC-4DFE-9C53-21CA51F84ECD
746Max-Forwards: 70
747From: sip:4414@sip.example.com;tag=D1F45773-0B5E-4155-B6C0-AF7E0DBDA1B3
748To: sip:3304128820@sip.example.com;tag=as344909d4
749Call-ID: 3B1E22FB-3601-4D79-82F1-68C22970B95C
750CSeq: 4312 ACK
751Content-Length:  0
752
753
754--end msg--
755 13:53:11.453   tsx0x1888464  State changed from Calling to Completed, event=RX_MSG
756 13:53:11.453   dlg0x187e064  Received Response msg 407/INVITE/cseq=4312 (rdata0x182b664)
757 13:53:11.453   dlg0x187e064  Transaction tsx0x1888464 state changed to Completed
758 13:53:11.453   inv0x187e064  Sending Request msg INVITE/cseq=4312 (tdta0x1886400)
759 13:53:11.453   dlg0x187e064  Sending Request msg INVITE/cseq=4312 (tdta0x1886400)
760 13:53:11.454   tsx0x188bc64  Transaction created for Request msg INVITE/cseq=4313 (tdta0x1886400)
761 13:53:11.454   tsx0x188bc64  Sending Request msg INVITE/cseq=4313 (tdta0x1886400) in state Null
762 13:53:11.454       endpoint  Request msg INVITE/cseq=4313 (tdta0x1886400): skipping target resolution because address is already set
763 13:53:11.454       endpoint  Request msg INVITE/cseq=4313 (tdta0x1886400) exceeds UDP size threshold (1300), sending with TCP
764 13:53:11.454  tcpc0x188c414  TCP client transport created
765 13:53:11.454  tcpc0x188c414  TCP transport 10.127.1.99:49241 is connecting to 173.8.19.148:5060...
766 13:53:11.454   pjsua_core.c  TX 1319 bytes Request msg INVITE/cseq=4313 (tdta0x1886400) to tcp 173.8.19.148:5060:
767INVITE sip:3304128820@sip.example.com SIP/2.0
768Via: SIP/2.0/TCP 10.127.1.99:49241;rport;branch=z9hG4bKPj576EEE7D-0CB6-4BF5-8B44-01ED3D1755A8
769Max-Forwards: 70
770From: sip:4414@sip.example.com;tag=D1F45773-0B5E-4155-B6C0-AF7E0DBDA1B3
771To: sip:3304128820@sip.example.com
772Contact: <sip:4414@66.219.174.73:5060;transport=UDP>
773Call-ID: 3B1E22FB-3601-4D79-82F1-68C22970B95C
774CSeq: 4313 INVITE
775Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
776Supported: replaces, 100rel, timer, norefersub
777Session-Expires: 1800
778Min-SE: 90
779User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
780Proxy-Authorization: Digest username="4414", realm="asterisk", nonce="0f1f398a", uri="sip:3304128820@sip.example.com", response="1e53a05dc75c8578029616a0fc288138", algorithm=MD5
781Content-Type: application/sdp
782Content-Length:   456
783
784v=0
785o=- 3468595991 3468595991 IN IP4 10.127.1.99
786s=pjmedia
787c=IN IP4 10.127.1.99
788t=0 0
789a=X-nat:0
790m=audio 7000 RTP/AVP 103 102 104 113 3 0 8 9 101
791a=rtcp:7001 IN IP4 10.127.1.99
792a=rtpmap:103 speex/16000
793a=rtpmap:102 speex/8000
794a=rtpmap:104 speex/32000
795a=rtpmap:113 iLBC/8000
796a=fmtp:113 mode=30
797a=rtpmap:3 GSM/8000
798a=rtpmap:0 PCMU/8000
799a=rtpmap:8 PCMA/8000
800a=rtpmap:9 G722/8000
801a=sendrecv
802a=rtpmap:101 telephone-event/8000
803a=fmtp:101 0-15
804
805--end msg--
806 13:53:11.455   tsx0x188bc64  State changed from Null to Calling, event=TX_MSG
807 13:53:11.455   dlg0x187e064  Transaction tsx0x188bc64 state changed to Calling
808 13:53:11.455    pjsua_app.c  Call 0 state changed to CALLING
809 13:53:14.881    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
810 13:53:14.881  tdta0x1888c00  Destroying txdata raw
811 13:53:15.890   sound_port.c  EC suspended because of inactivity
812 13:53:29.883    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
813 13:53:29.883  tdta0x1888c00  Destroying txdata raw
814 13:53:43.461   tsx0x188bc64  Timeout timer event
815 13:53:43.461   tsx0x188bc64  State changed from Calling to Terminated, event=TIMER
816 13:53:43.461   dlg0x187e064  Transaction tsx0x188bc64 state changed to Terminated
817 13:53:43.461    pjsua_app.c  Call 0 is DISCONNECTED [reason=408 (Request Timeout)]
818 13:53:43.462    pjsua_app.c  Call 0 disconnected, dumping media stats..
819 13:53:43.462    pjsua_app.c 
820  [DISCONNCTD] To: sip:3304128820@sip.example.com
821    Call time: 00h:00m:00s, 1st res in 32577 ms, conn in 0ms
822    SRTP status: Not active Crypto-suite: (null)
823 13:53:43.462        _krtp.c  transport_media_stop
824 13:53:43.508        _krtp.c  TCB Session Destroyed
825 13:53:43.509        _krtp.c  Last RTP packet Rx 33 seconds ago
826 13:53:43.510        _krtp.c  Last RTP packet Tx 33 seconds ago
827 13:53:43.510        _krtp.c  Stats - Pkts Rx: 0 Tx: 0 Dscrd Rx: 0 Tx: 0
828 13:53:43.510        _krtp.c          Pkts Delivered: 0 Probes: 0 DupRx: 0
829 13:53:43.510        _krtp.c          Cipher Rx: 0 Tx: 0 Error Rx: 0 Tx: 0
830 13:53:43.511        _krtp.c          OOO Pkts: 0 Seg: 0 Discrd: 0 Lost: 0
831 13:53:43.511        _krtp.c          RX Net Interval min/max/avg: 60 0 0
832 13:53:43.511        _krtp.c          RX Dlvr Interval min/max/avg: 60 0 0
833 13:53:43.511        _krtp.c          TX Interval min/max/avg: 20 0 0
834 13:53:43.511        _krtp.c          Audio Underrun c/m/m/a: 0 -1 0 0
835 13:53:43.511        _krtp.c          Audio Buffered max/avg: 0 -1
836 13:53:43.511        _krtp.c          Tx Audio Frames req/pro: 0 0
837 13:53:43.511        _krtp.c          Coalesce Factor: 3
838 13:53:43.512   dlg0x187e064  Session count dec to 1 by mod-invite
839 13:53:43.512   tsx0x1888464  Timeout timer event
840 13:53:43.512   tsx0x1888464  State changed from Completed to Terminated, event=TIMER
841 13:53:43.512   dlg0x187e064  Transaction tsx0x1888464 state changed to Terminated
842 13:53:43.512   dlg0x187e064  Dialog destroyed
843 13:53:43.522   tsx0x1888464  Timeout timer event
844 13:53:43.522   tsx0x1888464  State changed from Terminated to Destroyed, event=TIMER
845 13:53:43.522  tdta0x1889c00  Destroying txdata Request msg ACK/cseq=4312 (tdta0x1889c00)
846 13:53:43.522   tsx0x1888464  Transaction destroyed!
847 13:53:44.514  pjsua_media.c  Closing sound device after idle for 1 seconds
848 13:53:44.514  pjsua_media.c  Closing Built-in Output sound playback device and Built-in Microphone sound capture device
849 13:53:44.535       pa_dev.c  Stopping stream..
850 13:53:44.761       pa_dev.c  Done, status=0
851 13:53:44.761       pa_dev.c  Closing Built-in Microphone: 0 underflow, 0 overflow
852 13:53:44.883    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
853 13:53:44.883  tdta0x182d000  Destroying txdata raw
854 13:53:59.892    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
855 13:53:59.892  tdta0x182d000  Destroying txdata raw
856 13:54:00.030 sip_endpoint.c  Processing incoming message: Request msg OPTIONS/cseq=102 (rdata0x182b664)
857 13:54:00.030   pjsua_core.c  RX 535 bytes Request msg OPTIONS/cseq=102 (rdata0x182b664) from UDP 173.8.19.148:5060:
858OPTIONS sip:4414@66.219.174.73:5060;transport=UDP SIP/2.0
859Via: SIP/2.0/UDP 173.8.19.148:5060;branch=z9hG4bK6e69bf4b;rport
860From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as11d5bf32
861To: <sip:4414@66.219.174.73:5060;transport=UDP>
862Contact: <sip:Unknown@173.8.19.148>
863Call-ID: 725c2f5f6bbdf1ca27b4974e6d62bd72@173.8.19.148
864CSeq: 102 OPTIONS
865User-Agent: Asterisk PBX
866Max-Forwards: 70
867Date: Mon, 30 Nov 2009 20:07:37 GMT
868Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
869Supported: replaces
870Content-Length: 0
871
872
873--end msg--
874 13:54:00.030       endpoint  Response msg 200/OPTIONS/cseq=102 (tdta0x185ac00) created
875 13:54:00.030   pjsua_core.c  TX 1188 bytes Response msg 200/OPTIONS/cseq=102 (tdta0x185ac00) to UDP 173.8.19.148:5060:
876SIP/2.0 200 OK
877Via: SIP/2.0/UDP 173.8.19.148:5060;rport=5060;received=173.8.19.148;branch=z9hG4bK6e69bf4b
878Call-ID: 725c2f5f6bbdf1ca27b4974e6d62bd72@173.8.19.148
879From: "Unknown" <sip:Unknown@173.8.19.148>;tag=as11d5bf32
880To: <sip:4414@66.219.174.73>
881CSeq: 102 OPTIONS
882Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
883Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
884Supported: replaces, 100rel, timer, norefersub
885Allow-Events: presence, message-summary, refer
886User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
887Content-Type: application/sdp
888Content-Length:   445
889
890v=0
891o=- 3468596040 3468596040 IN IP4 10.127.1.99
892s=pjmedia
893c=IN IP4 10.127.1.99
894t=0 0
895m=audio 7000 RTP/AVP 103 102 104 113 3 0 8 9 101
896a=rtcp:7001 IN IP4 10.127.1.99
897a=rtpmap:103 speex/16000
898a=rtpmap:102 speex/8000
899a=rtpmap:104 speex/32000
900a=rtpmap:113 iLBC/8000
901a=fmtp:113 mode=30
902a=rtpmap:3 GSM/8000
903a=rtpmap:0 PCMU/8000
904a=rtpmap:8 PCMA/8000
905a=rtpmap:9 G722/8000
906a=sendrecv
907a=rtpmap:101 telephone-event/8000
908a=fmtp:101 0-15
909
910--end msg--
911 13:54:00.031  tdta0x185ac00  Destroying txdata Response msg 200/OPTIONS/cseq=102 (tdta0x185ac00)
912 13:54:14.894    pjsua_acc.c  Sending 2 bytes keep-alive packet for acc 2 to 173.8.19.148:5060
913 13:54:14.894  tdta0x182d000  Destroying txdata raw
914 13:54:26.231  tcpc0x188c414  TCP connect() error: Unknown error 60 [code=60]
915 13:54:26.231   tsx0x188bc64  Failed to send Request msg INVITE/cseq=4313 (tdta0x1886400)! err=60 (Unknown error 60)
916 13:54:26.231   tsx0x188bc64  State changed from Terminated to Destroyed, event=TRANSPORT_ERROR
917 13:54:26.231   tsx0x188bc64  Transaction destroyed!
918 13:54:26.231   pjsua_core.c  TX 1320 bytes Request msg INVITE/cseq=4313 (tdta0x1886400) to UDP 173.8.19.148:5060:
919INVITE sip:3304128820@sip.example.com SIP/2.0
920Via: SIP/2.0/UDP 66.219.174.73:5060;rport;branch=z9hG4bKPj576EEE7D-0CB6-4BF5-8B44-01ED3D1755A8
921Max-Forwards: 70
922From: sip:4414@sip.example.com;tag=D1F45773-0B5E-4155-B6C0-AF7E0DBDA1B3
923To: sip:3304128820@sip.example.com
924Contact: <sip:4414@66.219.174.73:5060;transport=UDP>
925Call-ID: 3B1E22FB-3601-4D79-82F1-68C22970B95C
926CSeq: 4313 INVITE
927Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
928Supported: replaces, 100rel, timer, norefersub
929Session-Expires: 1800
930Min-SE: 90
931User-Agent: PJSUA v1.5/i386-apple-darwin8.11.1
932Proxy-Authorization: Digest username="4414", realm="asterisk", nonce="0f1f398a", uri="sip:3304128820@sip.example.com", response="1e53a05dc75c8578029616a0fc288138", algorithm=MD5
933Content-Type: application/sdp
934Content-Length:   456
935
936v=0
937o=- 3468595991 3468595991 IN IP4 10.127.1.99
938s=pjmedia
939c=IN IP4 10.127.1.99
940t=0 0
941a=X-nat:0
942m=audio 7000 RTP/AVP 103 102 104 113 3 0 8 9 101
943a=rtcp:7001 IN IP4 10.127.1.99
944a=rtpmap:103 speex/16000
945a=rtpmap:102 speex/8000
946a=rtpmap:104 speex/32000
947a=rtpmap:113 iLBC/8000
948a=fmtp:113 mode=30
949a=rtpmap:3 GSM/8000
950a=rtpmap:0 PCMU/8000
951a=rtpmap:8 PCMA/8000
952a=rtpmap:9 G722/8000
953a=sendrecv
954a=rtpmap:101 telephone-event/8000
955a=fmtp:101 0-15
956
957--end msg--
958 13:54:26.233   tsx0x188bc64  State changed from Destroyed to Destroyed, event=UNIDENTIFIED