Ticket #473: messages

File messages, 18.5 KB (added by roman_zhur, 17 hours ago)

лог с VE-02

Line 
1Feb 9 09:17:41 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=5
2Feb 9 09:17:41 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: CAS event, ts=254, flags=0000, data=5
3Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: DTMF detected, ts=254, flags=0000, data=2
4Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone completed, ts=254, flags=0000, data=3
5Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone detected, ts=254, flags=0000, data=255
6Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: DTMF detected, ts=254, flags=0000, data=2
7Feb 9 09:17:42 sip_ua[454]: fxs.cpp:275: ts 254: dialing 22
8Feb 9 09:17:42 sip_ua[454]: user_agent.cpp:3909: --> ua_dial_out() <sip:11@192.168.20.120> -> sip:22@192.168.20.120...
9Feb 9 09:17:42 sip_ua[836]: repro.cpp:658: doSessionAccounting(): Session Created 'branch=z9hG4bK1917250191'
10Feb 9 09:17:42 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 2 (New call received!): cid=16, did=17, tid=32, rid=0, sid=0, nid=0
11Feb 9 09:17:42 sip_ua[482]: user_agent.cpp:2289: INVITE received: sip:22@127.0.0.1:6060;transport=udp (Call-ID: 1568766628@(null))
12Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Incoming call, ts=-1, flags=0001, data=16
13Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Incoming call, ts=-1, flags=0001, data=16
14Feb 9 09:17:42 sip_ua[454]: fxs.cpp:1023: channel 255: ringing
15Feb 9 09:17:42 sip_ua[454]: user_agent.cpp:4353: Call 16 routed to TS 255
16Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Ringing: CAS event, ts=255, flags=0000, data=13
17Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Tone detected, ts=254, flags=0000, data=255
18Feb 9 09:17:42 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 6 (Remote phone is ringing!): cid=15, did=18, tid=31, rid=0, sid=0, nid=0
19Feb 9 09:17:42 sip_ua[482]: user_agent.cpp:2516: ---> ringing with status code 180
20Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Remote is ringing, ts=254, flags=0000, data=15
21Feb 9 09:17:42 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 14 (New request received!): cid=16, did=17, tid=34, rid=0, sid=0, nid=0
22Feb 9 09:17:42 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 16 (2xx received for request!): cid=15, did=18, tid=33, rid=0, sid=0, nid=0
23Feb 9 09:17:42 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Message answered 2xx, ts=254, flags=0000, data=15
24Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Ringing: Caller ID sending complete, ts=255, flags=0000, data=0
25Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Ringing: CAS event, ts=255, flags=0000, data=5
26Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:6464: channel 255: answer
27Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP parameters, ts=255, flags=0000, data=16
28Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7300: --> ts 255: 192.168.20.120[10510] --> 192.168.20.120[10508]
29Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7301: --> ts 255: codec PCMA, VAD is on, red=0
30Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7302: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
31Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7406: routing 192.168.20.120 to 192.168.20.120 (lo)
32Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7418: getMac(192.168.20.120): 02:ad:c5:00:03:8f
33Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7428: ts 255: RTP destination is 02:ad:c5:00:03:8f
34Feb 9 09:17:45 sip_ua[836]: repro.cpp:882: doSessionAccounting(): Session Established 'branch=z9hG4bK1917250191'
35Feb 9 09:17:45 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 7 (Remote phone has answered!): cid=15, did=18, tid=31, rid=0, sid=0, nid=0
36Feb 9 09:17:45 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 12 (ACK received!): cid=16, did=17, tid=32, rid=0, sid=0, nid=0
37Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7125: ts 255: starting RTP stream
38Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: RTP parameters, ts=254, flags=0000, data=15
39Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7300: --> ts 254: 192.168.20.120[10508] --> 192.168.20.120[10510]
40Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7301: --> ts 254: codec PCMA, VAD is on, red=0
41Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7302: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
42Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7406: routing 192.168.20.120 to 192.168.20.120 (lo)
43Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7418: getMac(192.168.20.120): 02:ad:c5:00:03:8f
44Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7428: ts 254: RTP destination is 02:ad:c5:00:03:8f
45Feb 9 09:17:45 sip_ua[454]: comcerto.cpp:7125: ts 254: starting RTP stream
46Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Call answered, ts=254, flags=0000, data=15
47Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: ACK received, ts=255, flags=0000, data=16
48Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: Statistics received, ts=255, flags=0000, data=0
49Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: Statistics received, ts=255, flags=0000, data=0
50Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: RTP monitor, ts=254, flags=0000, data=1
51Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Tone completed, ts=254, flags=0000, data=3
52Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Statistics received, ts=254, flags=0000, data=0
53Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Statistics received, ts=254, flags=0000, data=0
54Feb 9 09:17:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP monitor, ts=255, flags=0000, data=1
55Feb 9 09:17:46 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP monitor, ts=255, flags=0000, data=0
56Feb 9 09:17:46 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP monitor, ts=255, flags=0000, data=1
57Feb 9 09:17:47 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: CAS event, ts=255, flags=0000, data=13
58Feb 9 09:17:47 sip_ua[454]: comcerto.cpp:7146: ts 255: stopping RTP stream
59Feb 9 09:17:47 sip_ua[836]: repro.cpp:792: doSessionAccounting(): Session Ended 'branch=z9hG4bK1347862967'
60Feb 9 09:17:47 sip_ua[836]: repro.cpp:810: --> duration=2, [FS01]tel:11@192.168.20.120: ---> [FS01]sip:22@192.168.20.120:
61Feb 9 09:17:47 sip_ua[836]: repro.cpp:1071: --> CDR: {"answer":1770628665,"duration":2,"hangup":1770628667,"org-host":"192.168.20.120","org-scheme":"tel","org-type":"FS01","org-user":"11","to-host":"192.168.20.120","to-scheme":"sip","to-type":"FS01",
62Feb 9 09:17:47 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 14 (New request received!): cid=15, did=18, tid=36, rid=0, sid=0, nid=0
63Feb 9 09:17:47 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 21 (Bye Received!): cid=15, did=18, tid=36, rid=0, sid=0, nid=0
64Feb 9 09:17:47 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 16 (2xx received for request!): cid=16, did=-1, tid=35, rid=0, sid=0, nid=0
65Feb 9 09:17:47 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Call disconnected, ts=255, flags=0000, data=16
66Feb 9 09:17:47 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Call disconnected, ts=254, flags=0000, data=15
67Feb 9 09:17:47 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
68Feb 9 09:17:47 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
69Feb 9 09:17:47 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Message answered 2xx, ts=255, flags=0000, data=16
70Feb 9 09:17:47 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: CAS event, ts=255, flags=0000, data=13
71Feb 9 09:17:48 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Busy: RTP monitor, ts=254, flags=0000, data=0
72Feb 9 09:17:49 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Busy: CAS event, ts=254, flags=0000, data=13
73Feb 9 09:17:49 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=11
74Feb 9 09:17:49 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=13
75Feb 9 09:17:52 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 22 (Call Context is released!): cid=16, did=0, tid=0, rid=0, sid=0, nid=0
76Feb 9 09:18:06 sip_ua[481]: poller.cpp:923: ===> command globalconf received
77Feb 9 09:18:06 sip_ua[454]: poller.cpp:1279: DHCP client started (pid=864)
78Feb 9 09:18:06 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
79Feb 9 09:18:06 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
80Feb 9 09:18:06 sip_ua[454]: virtualChannel.cpp:195: cannot open /proc/sys/net/ipv6/conf/eth0/proxy_ndp: No such file or directory
81Feb 9 09:18:06 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0002, data=0
82Feb 9 09:18:06 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0002, data=0
83Feb 9 09:18:06 udhcpc[864]: udhcpc (v1.18.5) started
84Feb 9 09:18:06 udhcpc[864]: Sending discover...
85Feb 9 09:18:07 sip_ua[481]: poller.cpp:2529: duplicate request 3 (1026 ms)
86Feb 9 09:18:07 udhcpc[864]: Sending select for 192.168.0.124...
87Feb 9 09:18:08 udhcpc[864]: Lease of 192.168.0.124 obtained, lease time 14400
88Feb 9 09:18:08 sip_ua[454]: sip_ua.cpp:1128: IP change 192.168.20.120 --> 192.168.0.124 detected
89Feb 9 09:18:08 sip_ua[481]: poller.cpp:2529: duplicate request 3 (1857 ms)
90Feb 9 09:18:10 dnsmasq[368]: reading /tmp/resolv.conf.auto
91Feb 9 09:18:10 dnsmasq[368]: using nameserver 8.8.8.8#53
92Feb 9 09:18:10 dnsmasq[368]: using nameserver 192.168.0.13#53
93Feb 9 09:18:10 dnsmasq[368]: using nameserver 212.33.224.133#53
94Feb 9 09:18:10 dnsmasq[368]: using only locally-known addresses for lan
95Feb 9 09:18:10 sip_ua[481]: poller.cpp:2529: duplicate request 8 (355 ms)
96Feb 9 09:18:10 sip_ua[481]: poller.cpp:2529: duplicate request 9 (382 ms)
97Feb 9 09:18:10 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
98Feb 9 09:18:10 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
99Feb 9 09:18:10 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0001, data=1
100Feb 9 09:18:10 sip_ua[454]: user_agent.cpp:3821: ---> registering <sip:11@192.168.20.120> on sip:192.168.20.120 as <sip:11@192.168.0.124:5060;line=254>
101Feb 9 09:18:10 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0001, data=1
102Feb 9 09:18:10 sip_ua[454]: user_agent.cpp:3821: ---> registering <sip:22@192.168.20.120> on sip:192.168.20.120 as <sip:22@192.168.0.124:5060;line=255>
103Feb 9 09:18:10 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0002, data=1
104Feb 9 09:18:10 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0002, data=1
105Feb 9 09:18:10 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=254, flags=0000, data=0
106Feb 9 09:18:10 sip_ua[481]: poller.cpp:2529: duplicate request 11 (96 ms)
107Feb 9 09:18:11 sip_ua[481]: poller.cpp:2529: duplicate request 10 (450 ms)
108Feb 9 09:18:11 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=255, flags=0000, data=0
109Feb 9 09:18:11 sip_ua[481]: poller.cpp:2529: duplicate request 14 (188 ms)
110Feb 9 09:18:11 sip_ua[481]: poller.cpp:2529: duplicate request 13 (256 ms)
111Feb 9 09:18:11 sip_ua[481]: poller.cpp:923: ===> command sslapply received
112Feb 9 09:18:11 sip_ua[481]: poller.cpp:923: ===> command userlist received
113Feb 9 09:18:11 sip_ua[481]: repro.cpp:1954: User directory updated
114Feb 9 09:18:11 sip_ua[481]: poller.cpp:923: ===> command ctime received
115Feb 9 09:18:11 sip_ua[481]: poller.cpp:923: ===> command callgroups received
116Feb 9 09:18:11 sip_ua[481]: poller.cpp:923: ===> command routes received
117Feb 9 09:18:11 sip_ua[481]: poller.cpp:923: ===> command conferences received
118Feb 9 09:18:11 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
119Feb 9 09:18:11 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
120Feb 9 09:18:16 sip_ua[458]: regSyncAgent.cpp:842: connected to repro
121Feb 9 09:18:19 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 22 (Call Context is released!): cid=15, did=0, tid=0, rid=0, sid=0, nid=0
122Feb 9 09:18:26 sip_ua[481]: poller.cpp:923: ===> command globalconf received
123Feb 9 09:18:26 udhcpc[864]: Received SIGTERM
124Feb 9 09:18:26 udhcpc[864]: Unicasting a release of 192.168.0.124 to 192.168.0.13
125Feb 9 09:18:26 udhcpc[864]: Sending release...
126Feb 9 09:18:26 udhcpc[864]: Entering released state
127Feb 9 09:18:26 dnsmasq[368]: reading /tmp/resolv.conf.auto
128Feb 9 09:18:26 dnsmasq[368]: using nameserver 8.8.8.8#53
129Feb 9 09:18:26 dnsmasq[368]: using only locally-known addresses for lan
130Feb 9 09:18:26 sip_ua[454]: poller.cpp:3345: DHCP client (pid 864) exited with return code 0
131Feb 9 09:18:26 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
132Feb 9 09:18:26 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
133Feb 9 09:18:26 sip_ua[454]: virtualChannel.cpp:195: cannot open /proc/sys/net/ipv6/conf/eth0/proxy_ndp: No such file or directory
134Feb 9 09:18:26 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0002, data=0
135Feb 9 09:18:26 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0002, data=0
136Feb 9 09:18:27 sip_ua[454]: sip_ua.cpp:1128: IP change 192.168.0.124 --> 192.168.20.120 detected
137Feb 9 09:18:28 sip_ua[481]: poller.cpp:2529: duplicate request 3 (2041 ms)
138Feb 9 09:18:30 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
139Feb 9 09:18:30 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
140Feb 9 09:18:30 sip_ua[481]: poller.cpp:923: ===> command globalconf received
141Feb 9 09:18:30 sip_ua[454]: comcerto.cpp:2639: comcerto_process_socket(): channel 0xffff: transaction 0x043f53 not found (530a 0602 043f 0000 0000 00e0)
142Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0001, data=1
143Feb 9 09:18:30 sip_ua[454]: user_agent.cpp:3865: cannot build REGISTER message (rc=-3)
144Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0001, data=1
145Feb 9 09:18:30 sip_ua[454]: user_agent.cpp:3865: cannot build REGISTER message (rc=-3)
146Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0002, data=1
147Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0002, data=1
148Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
149Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
150Feb 9 09:18:30 sip_ua[454]: virtualChannel.cpp:195: cannot open /proc/sys/net/ipv6/conf/eth0/proxy_ndp: No such file or directory
151Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0002, data=0
152Feb 9 09:18:30 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0002, data=0
153Feb 9 09:18:31 sip_ua[481]: poller.cpp:2529: duplicate request 7 (403 ms)
154Feb 9 09:18:31 sip_ua[481]: poller.cpp:923: ===> command sslapply received
155Feb 9 09:18:32 sip_ua[481]: poller.cpp:923: ===> command userlist received
156Feb 9 09:18:32 sip_ua[481]: repro.cpp:1954: User directory updated
157Feb 9 09:18:32 sip_ua[481]: poller.cpp:2529: duplicate request 16 (102 ms)
158Feb 9 09:18:32 sip_ua[481]: poller.cpp:923: ===> command ctime received
159Feb 9 09:18:32 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=254, flags=0000, data=0
160Feb 9 09:18:32 sip_ua[481]: poller.cpp:2529: duplicate request 19 (211 ms)
161Feb 9 09:18:32 sip_ua[481]: poller.cpp:2529: duplicate request 18 (478 ms)
162Feb 9 09:18:32 sip_ua[481]: poller.cpp:923: ===> command callgroups received
163Feb 9 09:18:32 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=255, flags=0000, data=0
164Feb 9 09:18:32 sip_ua[481]: poller.cpp:2529: duplicate request 22 (138 ms)
165Feb 9 09:18:32 sip_ua[481]: poller.cpp:2529: duplicate request 21 (249 ms)
166Feb 9 09:18:32 sip_ua[481]: poller.cpp:923: ===> command routes received
167Feb 9 09:18:33 sip_ua[481]: poller.cpp:923: ===> command conferences received
168Feb 9 09:18:33 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
169Feb 9 09:18:33 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
170Feb 9 09:18:36 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=5
171Feb 9 09:18:36 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: CAS event, ts=254, flags=0000, data=5
172Feb 9 09:18:36 sip_ua[458]: regSyncAgent.cpp:842: connected to repro
173Feb 9 09:18:37 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: DTMF detected, ts=254, flags=0000, data=2
174Feb 9 09:18:37 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone completed, ts=254, flags=0000, data=3
175Feb 9 09:18:37 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone detected, ts=254, flags=0000, data=255
176Feb 9 09:18:37 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: DTMF detected, ts=254, flags=0000, data=2
177Feb 9 09:18:37 sip_ua[454]: fxs.cpp:275: ts 254: dialing 22
178Feb 9 09:18:37 sip_ua[454]: user_agent.cpp:3909: --> ua_dial_out() <sip:11@192.168.20.120> -> sip:22@192.168.20.120...
179Feb 9 09:18:37 sip_ua[929]: repro.cpp:658: doSessionAccounting(): Session Created 'branch=z9hG4bK1344739134'
180Feb 9 09:18:37 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Tone detected, ts=254, flags=0000, data=255
181Feb 9 09:18:38 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 5 (Call is being processed!): cid=19, did=0, tid=39, rid=0, sid=0, nid=0
182Feb 9 09:19:09 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 9 (4xx received for Call!): cid=19, did=0, tid=39, rid=0, sid=0, nid=0
183Feb 9 09:19:09 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Call disconnected, ts=254, flags=0000, data=19
184Feb 9 09:19:09 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
185Feb 9 09:19:09 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
186Feb 9 09:19:12 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Busy: CAS event, ts=254, flags=0000, data=13
187Feb 9 09:19:12 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=13
188Feb 9 09:19:52 sip_ua[482]: user_agent.cpp:2151: ---> transport 0: SIP event 22 (Call Context is released!): cid=19, did=0, tid=0, rid=0, sid=0, nid=0