Ticket #473: messages.2

File messages.2, 22.3 KB (added by roman_zhur, 7 hours ago)
Line 
1Feb 11 05:09:27 init: starting pid 259, tty '/dev/ttyS0': '/bin/ash --login'
2Feb 11 05:10:44 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=254, flags=0000, data=0
3Feb 11 05:10:44 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=255, flags=0000, data=0
4Feb 11 05:10:44 sip_ua[477]: poller.cpp:923: ===> command globalconf received
5Feb 11 05:10:44 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
6Feb 11 05:10:44 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
7Feb 11 05:10:44 sip_ua[454]: virtualChannel.cpp:195: cannot open /proc/sys/net/ipv6/conf/eth0/proxy_ndp: No such file or directory
8Feb 11 05:10:44 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0002, data=0
9Feb 11 05:10:44 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0002, data=0
10Feb 11 05:10:44 sip_ua[477]: poller.cpp:923: ===> command userlist received
11Feb 11 05:10:44 sip_ua[477]: repro.cpp:1954: User directory updated
12Feb 11 05:10:45 sip_ua[477]: poller.cpp:2529: duplicate request 157 (345 ms)
13Feb 11 05:10:45 sip_ua[477]: poller.cpp:2529: duplicate request 158 (354 ms)
14Feb 11 05:10:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=254, flags=0000, data=0
15Feb 11 05:10:45 sip_ua[477]: poller.cpp:2529: duplicate request 161 (1 ms)
16Feb 11 05:10:45 sip_ua[477]: poller.cpp:2529: duplicate request 160 (236 ms)
17Feb 11 05:10:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=255, flags=0000, data=0
18Feb 11 05:10:46 sip_ua[477]: poller.cpp:923: ===> command sslapply received
19Feb 11 05:10:46 sip_ua[477]: poller.cpp:923: ===> command userlist received
20Feb 11 05:10:46 sip_ua[477]: repro.cpp:1954: User directory updated
21Feb 11 05:10:46 sip_ua[477]: poller.cpp:923: ===> command ctime received
22Feb 11 05:10:46 sip_ua[477]: poller.cpp:923: ===> command callgroups received
23Feb 11 05:10:46 sip_ua[477]: poller.cpp:923: ===> command routes received
24Feb 11 05:10:46 sip_ua[477]: poller.cpp:923: ===> command conferences received
25Feb 11 05:10:46 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
26Feb 11 05:10:46 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
27Feb 11 05:10:52 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=5
28Feb 11 05:10:52 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: CAS event, ts=254, flags=0000, data=5
29Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: DTMF detected, ts=254, flags=0000, data=2
30Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone completed, ts=254, flags=0000, data=3
31Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone detected, ts=254, flags=0000, data=255
32Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: DTMF detected, ts=254, flags=0000, data=2
33Feb 11 05:10:53 sip_ua[454]: fxs.cpp:275: ts 254: dialing 22
34Feb 11 05:10:53 sip_ua[454]: user_agent.cpp:3909: --> ua_dial_out() <sip:11@192.168.20.120> -> sip:22@192.168.20.120...
35Feb 11 05:10:53 sip_ua[588]: repro.cpp:658: doSessionAccounting(): Session Created 'branch=z9hG4bK1028353326'
36Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Tone detected, ts=254, flags=0000, data=255
37Feb 11 05:10:53 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 2 (New call received!): cid=2, did=3, tid=2, rid=0, sid=0, nid=0
38Feb 11 05:10:53 sip_ua[478]: user_agent.cpp:2289: INVITE received: sip:22@127.0.0.1:6060;transport=udp (Call-ID: 681690619@(null))
39Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Incoming call, ts=-1, flags=0001, data=2
40Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Incoming call, ts=-1, flags=0001, data=2
41Feb 11 05:10:53 sip_ua[454]: fxs.cpp:1023: channel 255: ringing
42Feb 11 05:10:53 sip_ua[454]: user_agent.cpp:4353: Call 2 routed to TS 255
43Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Ringing: CAS event, ts=255, flags=0000, data=13
44Feb 11 05:10:53 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 5 (Call is being processed!): cid=1, did=0, tid=1, rid=0, sid=0, nid=0
45Feb 11 05:10:53 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 6 (Remote phone is ringing!): cid=1, did=4, tid=1, rid=0, sid=0, nid=0
46Feb 11 05:10:53 sip_ua[478]: user_agent.cpp:2516: ---> ringing with status code 180
47Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Remote is ringing, ts=254, flags=0000, data=1
48Feb 11 05:10:53 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 14 (New request received!): cid=2, did=3, tid=4, rid=0, sid=0, nid=0
49Feb 11 05:10:53 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 16 (2xx received for request!): cid=1, did=4, tid=3, rid=0, sid=0, nid=0
50Feb 11 05:10:53 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Message answered 2xx, ts=254, flags=0000, data=1
51Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Ringing: Caller ID sending complete, ts=255, flags=0000, data=0
52Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Ringing: CAS event, ts=255, flags=0000, data=5
53Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:6464: channel 255: answer
54Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP parameters, ts=255, flags=0000, data=2
55Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7300: --> ts 255: 192.168.20.120[10510] --> 192.168.20.120[10508]
56Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7301: --> ts 255: codec PCMA, VAD is on, red=0
57Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7302: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
58Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7406: routing 192.168.20.120 to 192.168.20.120 (lo)
59Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7418: getMac(192.168.20.120): 02:ad:c5:00:03:8f
60Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7428: ts 255: RTP destination is 02:ad:c5:00:03:8f
61Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7146: ts 255: stopping RTP stream
62Feb 11 05:10:56 sip_ua[588]: repro.cpp:882: doSessionAccounting(): Session Established 'branch=z9hG4bK1028353326'
63Feb 11 05:10:56 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 7 (Remote phone has answered!): cid=1, did=4, tid=1, rid=0, sid=0, nid=0
64Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7146: ts 255: stopping RTP stream
65Feb 11 05:10:56 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 12 (ACK received!): cid=2, did=3, tid=2, rid=0, sid=0, nid=0
66Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7125: ts 255: starting RTP stream
67Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: RTP parameters, ts=254, flags=0000, data=1
68Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7300: --> ts 254: 192.168.20.120[10508] --> 192.168.20.120[10510]
69Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7301: --> ts 254: codec PCMA, VAD is on, red=0
70Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7302: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
71Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7406: routing 192.168.20.120 to 192.168.20.120 (lo)
72Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7418: getMac(192.168.20.120): 02:ad:c5:00:03:8f
73Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7428: ts 254: RTP destination is 02:ad:c5:00:03:8f
74Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
75Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
76Feb 11 05:10:56 sip_ua[454]: comcerto.cpp:7125: ts 254: starting RTP stream
77Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Call answered, ts=254, flags=0000, data=1
78Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: ACK received, ts=255, flags=0000, data=2
79Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: Statistics received, ts=255, flags=0000, data=0
80Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: Statistics received, ts=255, flags=0000, data=0
81Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: RTP monitor, ts=254, flags=0000, data=1
82Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Tone completed, ts=254, flags=0000, data=3
83Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Statistics received, ts=254, flags=0000, data=0
84Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Statistics received, ts=254, flags=0000, data=0
85Feb 11 05:10:56 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP monitor, ts=255, flags=0000, data=1
86Feb 11 05:10:57 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP monitor, ts=255, flags=0000, data=0
87Feb 11 05:10:57 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: RTP monitor, ts=255, flags=0000, data=1
88Feb 11 05:11:00 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Connected: CAS event, ts=255, flags=0000, data=13
89Feb 11 05:11:00 sip_ua[454]: comcerto.cpp:7146: ts 255: stopping RTP stream
90Feb 11 05:11:00 sip_ua[588]: repro.cpp:792: doSessionAccounting(): Session Ended 'branch=z9hG4bK1864719899'
91Feb 11 05:11:00 sip_ua[588]: repro.cpp:810: --> duration=4, [FS01]tel:11@192.168.20.120: ---> [FS01]sip:22@192.168.20.120:
92Feb 11 05:11:00 sip_ua[588]: repro.cpp:1071: --> CDR: {"answer":1770786656,"duration":4,"hangup":1770786660,"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",
93Feb 11 05:11:00 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Call disconnected, ts=255, flags=0000, data=2
94Feb 11 05:11:00 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: CAS event, ts=255, flags=0000, data=13
95Feb 11 05:11:00 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 14 (New request received!): cid=1, did=4, tid=6, rid=0, sid=0, nid=0
96Feb 11 05:11:00 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 21 (Bye Received!): cid=1, did=4, tid=6, rid=0, sid=0, nid=0
97Feb 11 05:11:00 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Connected: Call disconnected, ts=254, flags=0000, data=1
98Feb 11 05:11:00 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
99Feb 11 05:11:00 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
100Feb 11 05:11:00 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 16 (2xx received for request!): cid=2, did=-1, tid=5, rid=0, sid=0, nid=0
101Feb 11 05:11:00 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Message answered 2xx, ts=255, flags=0000, data=2
102Feb 11 05:11:01 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Busy: RTP monitor, ts=254, flags=0000, data=0
103Feb 11 05:11:01 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Busy: CAS event, ts=254, flags=0000, data=13
104Feb 11 05:11:01 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Tone completed, ts=254, flags=0000, data=3
105Feb 11 05:11:01 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=13
106Feb 11 05:11:05 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 22 (Call Context is released!): cid=2, did=0, tid=0, rid=0, sid=0, nid=0
107Feb 11 05:11:21 sip_ua[477]: poller.cpp:923: ===> command globalconf received
108Feb 11 05:11:21 sip_ua[454]: poller.cpp:1279: DHCP client started (pid=615)
109Feb 11 05:11:21 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
110Feb 11 05:11:21 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
111Feb 11 05:11:21 sip_ua[454]: virtualChannel.cpp:195: cannot open /proc/sys/net/ipv6/conf/eth0/proxy_ndp: No such file or directory
112Feb 11 05:11:21 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0002, data=0
113Feb 11 05:11:21 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0002, data=0
114Feb 11 05:11:21 udhcpc[615]: udhcpc (v1.18.5) started
115Feb 11 05:11:21 udhcpc[615]: Sending discover...
116Feb 11 05:11:21 sip_ua[477]: poller.cpp:2529: duplicate request 3 (446 ms)
117Feb 11 05:11:22 udhcpc[615]: Sending select for 192.168.0.124...
118Feb 11 05:11:22 udhcpc[615]: Lease of 192.168.0.124 obtained, lease time 14400
119Feb 11 05:11:23 sip_ua[477]: poller.cpp:2529: duplicate request 3 (1559 ms)
120Feb 11 05:11:23 sip_ua[454]: sip_ua.cpp:1128: IP change 192.168.20.120 --> 192.168.0.124 detected
121Feb 11 05:11:24 sip_ua[477]: poller.cpp:2529: duplicate request 9 (272 ms)
122Feb 11 05:11:24 dnsmasq[370]: reading /tmp/resolv.conf.auto
123Feb 11 05:11:24 dnsmasq[370]: using nameserver 8.8.8.8#53
124Feb 11 05:11:24 dnsmasq[370]: using nameserver 192.168.0.13#53
125Feb 11 05:11:24 dnsmasq[370]: using nameserver 212.33.224.133#53
126Feb 11 05:11:24 dnsmasq[370]: using only locally-known addresses for lan
127Feb 11 05:11:24 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
128Feb 11 05:11:24 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
129Feb 11 05:11:24 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0001, data=1
130Feb 11 05:11:24 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>
131Feb 11 05:11:24 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0001, data=1
132Feb 11 05:11:24 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>
133Feb 11 05:11:24 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0002, data=1
134Feb 11 05:11:24 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0002, data=1
135Feb 11 05:11:24 sip_ua[477]: poller.cpp:2529: duplicate request 8 (529 ms)
136Feb 11 05:11:25 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=254, flags=0000, data=0
137Feb 11 05:11:25 sip_ua[477]: poller.cpp:2529: duplicate request 11 (0 ms)
138Feb 11 05:11:25 sip_ua[477]: poller.cpp:2529: duplicate request 10 (251 ms)
139Feb 11 05:11:25 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=255, flags=0000, data=0
140Feb 11 05:11:25 sip_ua[477]: poller.cpp:923: ===> command sslapply received
141Feb 11 05:11:25 sip_ua[477]: poller.cpp:923: ===> command userlist received
142Feb 11 05:11:25 sip_ua[477]: repro.cpp:1954: User directory updated
143Feb 11 05:11:25 sip_ua[477]: poller.cpp:923: ===> command ctime received
144Feb 11 05:11:25 sip_ua[477]: poller.cpp:923: ===> command callgroups received
145Feb 11 05:11:25 sip_ua[477]: poller.cpp:923: ===> command routes received
146Feb 11 05:11:25 sip_ua[477]: poller.cpp:923: ===> command conferences received
147Feb 11 05:11:25 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
148Feb 11 05:11:25 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
149Feb 11 05:11:31 sip_ua[458]: regSyncAgent.cpp:842: connected to repro
150Feb 11 05:11:31 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 22 (Call Context is released!): cid=1, did=0, tid=0, rid=0, sid=0, nid=0
151Feb 11 05:11:43 sip_ua[477]: poller.cpp:923: ===> command globalconf received
152Feb 11 05:11:43 udhcpc[615]: Received SIGTERM
153Feb 11 05:11:43 udhcpc[615]: Unicasting a release of 192.168.0.124 to 192.168.0.13
154Feb 11 05:11:43 udhcpc[615]: Sending release...
155Feb 11 05:11:43 dnsmasq[370]: reading /tmp/resolv.conf.auto
156Feb 11 05:11:43 dnsmasq[370]: using nameserver 8.8.8.8#53
157Feb 11 05:11:43 dnsmasq[370]: using only locally-known addresses for lan
158Feb 11 05:11:43 udhcpc[615]: Entering released state
159Feb 11 05:11:43 sip_ua[454]: poller.cpp:3345: DHCP client (pid 615) exited with return code 0
160Feb 11 05:11:43 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
161Feb 11 05:11:43 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
162Feb 11 05:11:43 sip_ua[454]: virtualChannel.cpp:195: cannot open /proc/sys/net/ipv6/conf/eth0/proxy_ndp: No such file or directory
163Feb 11 05:11:43 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0002, data=0
164Feb 11 05:11:43 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0002, data=0
165Feb 11 05:11:43 sip_ua[454]: sip_ua.cpp:1128: IP change 192.168.0.124 --> 192.168.20.120 detected
166Feb 11 05:11:43 sip_ua[477]: poller.cpp:2529: duplicate request 3 (401 ms)
167Feb 11 05:11:44 sip_ua[477]: poller.cpp:2529: duplicate request 3 (1533 ms)
168Feb 11 05:11:44 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
169Feb 11 05:11:44 sip_ua[454]: repro.cpp:1570: --> skipping secure transport: no cert file
170Feb 11 05:11:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0001, data=1
171Feb 11 05:11:45 sip_ua[454]: user_agent.cpp:3865: cannot build REGISTER message (rc=-3)
172Feb 11 05:11:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0001, data=1
173Feb 11 05:11:45 sip_ua[454]: user_agent.cpp:3865: cannot build REGISTER message (rc=-3)
174Feb 11 05:11:45 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: IP address changed, ts=-1, flags=0002, data=1
175Feb 11 05:11:45 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: IP address changed, ts=-1, flags=0002, data=1
176Feb 11 05:11:46 sip_ua[477]: poller.cpp:2529: duplicate request 7 (357 ms)
177Feb 11 05:11:46 sip_ua[477]: poller.cpp:2529: duplicate request 8 (377 ms)
178Feb 11 05:11:47 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=254, flags=0000, data=0
179Feb 11 05:11:47 sip_ua[477]: poller.cpp:2529: duplicate request 11 (150 ms)
180Feb 11 05:11:47 sip_ua[477]: poller.cpp:2529: duplicate request 10 (417 ms)
181Feb 11 05:11:47 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=255, flags=0000, data=0
182Feb 11 05:11:47 sip_ua[477]: poller.cpp:2529: duplicate request 14 (106 ms)
183Feb 11 05:11:48 sip_ua[477]: poller.cpp:2529: duplicate request 13 (297 ms)
184Feb 11 05:11:48 sip_ua[477]: poller.cpp:923: ===> command sslapply received
185Feb 11 05:11:48 sip_ua[477]: poller.cpp:923: ===> command userlist received
186Feb 11 05:11:48 sip_ua[477]: repro.cpp:1954: User directory updated
187Feb 11 05:11:48 sip_ua[477]: poller.cpp:923: ===> command ctime received
188Feb 11 05:11:48 sip_ua[477]: poller.cpp:923: ===> command callgroups received
189Feb 11 05:11:48 sip_ua[477]: poller.cpp:923: ===> command routes received
190Feb 11 05:11:48 sip_ua[477]: poller.cpp:923: ===> command conferences received
191Feb 11 05:11:48 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: Channel settings, ts=-1, flags=0001, data=0
192Feb 11 05:11:48 sip_ua[454]: fxs.cpp:434: ---> ts=255, state=Idle: Channel settings, ts=-1, flags=0001, data=0
193Feb 11 05:11:51 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=5
194Feb 11 05:11:51 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: CAS event, ts=254, flags=0000, data=5
195Feb 11 05:11:51 sip_ua[458]: regSyncAgent.cpp:842: connected to repro
196Feb 11 05:11:52 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: DTMF detected, ts=254, flags=0000, data=2
197Feb 11 05:11:52 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone completed, ts=254, flags=0000, data=3
198Feb 11 05:11:52 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone detected, ts=254, flags=0000, data=255
199Feb 11 05:11:52 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: DTMF detected, ts=254, flags=0000, data=2
200Feb 11 05:11:52 sip_ua[454]: fxs.cpp:275: ts 254: dialing 22
201Feb 11 05:11:52 sip_ua[454]: user_agent.cpp:3909: --> ua_dial_out() <sip:11@192.168.20.120> -> sip:22@192.168.20.120...
202Feb 11 05:11:52 sip_ua[680]: repro.cpp:658: doSessionAccounting(): Session Created 'branch=z9hG4bK2075166962'
203Feb 11 05:11:52 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Tone detected, ts=254, flags=0000, data=255
204Feb 11 05:11:52 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 5 (Call is being processed!): cid=5, did=0, tid=9, rid=0, sid=0, nid=0
205Feb 11 05:12:24 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 9 (4xx received for Call!): cid=5, did=0, tid=9, rid=0, sid=0, nid=0
206Feb 11 05:12:24 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Call disconnected, ts=254, flags=0000, data=5
207Feb 11 05:12:24 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
208Feb 11 05:12:24 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
209Feb 11 05:12:27 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Busy: CAS event, ts=254, flags=0000, data=13
210Feb 11 05:12:27 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=13
211Feb 11 05:12:30 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=5
212Feb 11 05:12:30 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: CAS event, ts=254, flags=0000, data=5
213Feb 11 05:12:32 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialtone: DTMF detected, ts=254, flags=0000, data=2
214Feb 11 05:12:32 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone completed, ts=254, flags=0000, data=3
215Feb 11 05:12:32 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: Tone detected, ts=254, flags=0000, data=255
216Feb 11 05:12:32 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Dialing: DTMF detected, ts=254, flags=0000, data=2
217Feb 11 05:12:32 sip_ua[454]: fxs.cpp:275: ts 254: dialing 22
218Feb 11 05:12:32 sip_ua[454]: user_agent.cpp:3909: --> ua_dial_out() <sip:11@192.168.20.120> -> sip:22@192.168.20.120...
219Feb 11 05:12:32 sip_ua[680]: repro.cpp:658: doSessionAccounting(): Session Created 'branch=z9hG4bK603141738'
220Feb 11 05:12:32 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Tone detected, ts=254, flags=0000, data=255
221Feb 11 05:12:32 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 5 (Call is being processed!): cid=6, did=0, tid=10, rid=0, sid=0, nid=0
222Feb 11 05:12:36 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 10 (5xx received for Call!): cid=6, did=0, tid=10, rid=0, sid=0, nid=0
223Feb 11 05:12:36 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Calling: Call disconnected, ts=254, flags=0000, data=6
224Feb 11 05:12:36 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
225Feb 11 05:12:36 sip_ua[454]: comcerto.cpp:7146: ts 254: stopping RTP stream
226Feb 11 05:12:38 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Busy: CAS event, ts=254, flags=0000, data=13
227Feb 11 05:12:39 sip_ua[454]: fxs.cpp:434: ---> ts=254, state=Idle: CAS event, ts=254, flags=0000, data=13
228Feb 11 05:13:07 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 22 (Call Context is released!): cid=5, did=0, tid=0, rid=0, sid=0, nid=0
229Feb 11 05:13:18 sip_ua[478]: user_agent.cpp:2151: ---> transport 0: SIP event 22 (Call Context is released!): cid=6, did=0, tid=0, rid=0, sid=0, nid=0