Ticket #408: log01.txt

File log01.txt, 35.9 KB (added by san, 7 months ago)
Line 
1root@comcerto:~# logread -f
2Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Idle: CAS event, ts=1, flags=0000, data=7
3Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:275: ts 1: dialing 0
4Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: user_agent.cpp:3968: --> ua_dial_out() <sip:200@192.168.0.104> -> sip:0@192.168.0.104 ()...
5Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: CAS event, ts=1, flags=0000, data=7
6Oct 11 10:59:52 comcerto daemon.info sip_ua[462]: repro.cpp:608: doSessionAccounting(): Session Created 'branch=z9hG4bK1086409190'
7Oct 11 10:59:52 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 2 (New call received!): cid=86, did=87, tid=122, rid=0, si d=0, nid=0
8Oct 11 10:59:52 comcerto daemon.info sip_ua[416]: user_agent.cpp:2354: INVITE received: sip:0@127.0.0.1:6060;transport=udp (Call-ID: 1059966917@(null))
9Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: Incoming call, ts=-1, flags=0001, data=86
10Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0001, data=86
11Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Idle: Incoming call, ts=-1, flags=0001, data=86
12Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0001, data=86
13Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Idle: Incoming call, ts=-1, flags=0001, data=86
14Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Incoming call, ts=-1, flags=0001, data=86
15Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Incoming call, ts=-1, flags=0001, data=86
16Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: virtualChannel.cpp:194: ---> VirtualChannelManager: Incoming call, ts=-1, flags=0001, data=86
17Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: Incoming call, ts=-1, flags=0002, data=86
18Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0002, data=86
19Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Idle: Incoming call, ts=-1, flags=0002, data=86
20Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0002, data=86
21Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Idle: Incoming call, ts=-1, flags=0002, data=86
22Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:179: B2[5]: >>> sending message: 1 (Connect)
23Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 1 (size 3): 32 30 30
24Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 2 (size 0):
25Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 3 (size 1): 30
26Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: user_agent.cpp:4451: Call 86 routed to TS 5
27Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=PreAnswer: RTP monitor, ts=5, flags=0000, data=0
28Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Tone detected, ts=6, flags=0000, data=112
29Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Idle: Tone detected, ts=3, flags=0000, data=112
30Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Tone detected, ts=7, flags=0000, data=112
31Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Tone detected, ts=4, flags=0000, data=112
32Oct 11 10:59:52 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 5 (Call is being processed!): cid=85, did=0, tid=121, rid= 0, sid=0, nid=0
33Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Idle: Tone detected, ts=3, flags=0000, data=113
34Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Tone detected, ts=7, flags=0000, data=113
35Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Tone detected, ts=4, flags=0000, data=113
36Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Tone detected, ts=6, flags=0000, data=113
37Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Idle: DTMF detected, ts=3, flags=0000, data=15
38Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: DTMF detected, ts=7, flags=0000, data=15
39Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Idle: Any Data, ts=3, flags=0000, data=0
40Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[3]: <<< data received: b2 0b 01 01 03 32 30 30 02 00 03 01 30 00
41Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[3]: <<< received message: 1 (Connect)
42Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 1 (size 3): 32 30 30
43Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 2 (size 0):
44Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 3 (size 1): 30
45Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:147: ts 3: dialing 111@192.168.0.104
46Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: user_agent.cpp:3968: --> ua_dial_out() <sip:200@192.168.0.104> -> sip:111@192.168.0.104 ()...
47Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Any Data, ts=7, flags=0000, data=0
48Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[7]: <<< data received: b2 0b 01 01 03 32 30 30 02 00 03 01 30 00
49Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[7]: <<< received message: 1 (Connect)
50Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 1 (size 3): 32 30 30
51Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 2 (size 0):
52Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 3 (size 1): 30
53Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Any Data, ts=4, flags=0000, data=0
54Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[4]: <<< data received: b2 0b 01 01 03 32 30 30 02 00 03 01 30 00
55Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[4]: <<< received message: 1 (Connect)
56Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 1 (size 3): 32 30 30
57Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 2 (size 0):
58Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:6263: channel 5: answer
59Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: RTP parameters, ts=5, flags=0000, data=86
60Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7099: --> ts 5: 192.168.0.104[10010] --> 192.168.0.104[10002]
61Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 5: codec PCMA, VAD is off, red=0
62Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7101: --> audio pt: 8/8, event pt: 101/101, VBD pt: -1/-1
63Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo)
64Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac
65Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 5: RTP destination is 02:ad:c3:00:01:ac
66Oct 11 10:59:53 comcerto daemon.info sip_ua[462]: repro.cpp:832: doSessionAccounting(): Session Established 'branch=z9hG4bK1086409190'
67Oct 11 10:59:53 comcerto daemon.info sip_ua[462]: repro.cpp:608: doSessionAccounting(): Session Created 'branch=z9hG4bK997555784'
68Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 5: starting RTP stream
69Oct 11 10:59:53 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 7 (Remote phone has answered!): cid=85, did=89, tid=121, r id=0, sid=0, nid=0
70Oct 11 10:59:53 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 6 (Remote phone is ringing!): cid=88, did=90, tid=123, rid =0, sid=0, nid=0
71Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: RTP parameters, ts=1, flags=0000, data=85
72Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7099: --> ts 1: 192.168.0.104[10002] --> 192.168.0.104[10010]
73Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 1: codec PCMA, VAD is off, red=0
74Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7101: --> audio pt: 8/8, event pt: 101/101, VBD pt: -1/-1
75Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo)
76Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac
77Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 1: RTP destination is 02:ad:c3:00:01:ac
78Oct 11 10:59:53 comcerto daemon.info sip_ua[416]: user_agent.cpp:2575: ---> ringing with status code 180
79Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 1: starting RTP stream
80Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: Call answered, ts=1, flags=0000, data=85
81Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
82Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
83Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Calling: Remote is ringing, ts=3, flags=0000, data=88
84Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: RTP monitor, ts=1, flags=0000, data=1
85Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
86Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
87Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: RTP monitor, ts=5, flags=0000, data=1
88Oct 11 10:59:53 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 12 (ACK received!): cid=86, did=87, tid=122, rid=0, sid=0, nid=0
89Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: ACK received, ts=5, flags=0000, data=86
90Oct 11 10:59:57 comcerto daemon.info sip_ua[462]: repro.cpp:832: doSessionAccounting(): Session Established 'branch=z9hG4bK997555784'
91Oct 11 10:59:58 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 7 (Remote phone has answered!): cid=88, did=90, tid=123, r id=0, sid=0, nid=0
92Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Calling: RTP parameters, ts=3, flags=0000, data=88
93Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: comcerto.cpp:7099: --> ts 3: 192.168.0.104[10006] --> 192.168.0.105[12702]
94Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 3: codec PCMA, VAD is off, red=0
95Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: comcerto.cpp:7101: --> audio pt: 8/8, event pt: 101/101, VBD pt: -1/-1
96Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.105 to 192.168.0.105 (eth0)
97Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.105): 00:15:65:a3:cf:f6
98Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 3: RTP destination is 00:15:65:a3:cf:f6
99Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 3: starting RTP stream
100Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Calling: Call answered, ts=3, flags=0000, data=88
101Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:179: B2[3]: >>> sending message: 1 (Connect)
102Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[3]: >>> parameter: 1 (size 3): 31 31 31
103Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Tone detected, ts=4, flags=0000, data=112
104Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Tone detected, ts=6, flags=0000, data=112
105Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Tone detected, ts=7, flags=0000, data=112
106Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Tone detected, ts=5, flags=0000, data=112
107Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Tone detected, ts=4, flags=0000, data=113
108Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Tone detected, ts=5, flags=0000, data=113
109Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Tone detected, ts=6, flags=0000, data=113
110Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Tone detected, ts=7, flags=0000, data=113
111Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Tone detected, ts=6, flags=0000, data=255
112Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Tone detected, ts=7, flags=0000, data=255
113Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Tone detected, ts=5, flags=0000, data=255
114Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
115Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
116Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
117Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
118Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Any Data, ts=5, flags=0000, data=0
119Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[5]: <<< data received: b2 06 01 01 03 31 31 31 00 00
120Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[5]: <<< received message: 1 (Connect)
121Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[5]: <<< parameter 1 (size 3): 31 31 31
122Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Caller ID sending complete, ts=3, flags=0000, data=0
123Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Any Data, ts=7, flags=0000, data=0
124Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[7]: <<< data received: b2 06 01 01 03 31 31 31 00 00
125Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[7]: <<< received message: 1 (Connect)
126Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 1 (size 3): 31 31 31
127Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Any Data, ts=4, flags=0000, data=0
128Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[4]: <<< data received: b2 06 01 01 03 31 31 31 00 00
129Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[4]: <<< received message: 1 (Connect)
130Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 1 (size 3): 31 31 31
131Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: RTP monitor, ts=3, flags=0000, data=1
132Oct 11 10:59:58 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 14 (New request received!): cid=85, did=89, tid=125, rid=0 , sid=0, nid=0
133Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
134Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
135Oct 11 10:59:58 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 16 (2xx received for request!): cid=86, did=87, tid=124, r id=0, sid=0, nid=0
136Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Message answered 2xx, ts=5, flags=0000, data=86
137Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: RTP monitor, ts=1, flags=0000, data=0
138Oct 11 10:59:59 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: RTP monitor, ts=1, flags=0000, data=1
139Oct 11 11:00:03 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
140Oct 11 11:00:03 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
141Oct 11 11:00:03 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
142Oct 11 11:00:03 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
143Oct 11 11:00:03 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
144Oct 11 11:00:03 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
145Oct 11 11:00:03 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 14 (New request received!): cid=85, did=89, tid=127, rid=0 , sid=0, nid=0
146Oct 11 11:00:03 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 16 (2xx received for request!): cid=86, did=87, tid=126, r id=0, sid=0, nid=0
147Oct 11 11:00:03 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Message answered 2xx, ts=5, flags=0000, data=86
148Oct 11 11:00:04 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: CAS event, ts=1, flags=0000, data=15
149Oct 11 11:00:04 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 1: stopping RTP stream
150Oct 11 11:00:04 comcerto daemon.info sip_ua[462]: repro.cpp:742: doSessionAccounting(): Session Ended 'branch=z9hG4bK2087124730'
151Oct 11 11:00:04 comcerto daemon.info sip_ua[462]: repro.cpp:760: --> duration=11, [FXS]tel:200@192.168.0.104: ---> [B2]sip:op2@192.168.0.104:
152Oct 11 11:00:04 comcerto daemon.info sip_ua[462]: repro.cpp:1021: --> CDR: {"answer":1697021993,"duration":11,"hangup":1697022004,"org-host":"192.168.0.104"," org-scheme":"tel","org-type":"FXS","org-user":"200","to-host":"192.168.0.104","to-scheme":"sip","to-type":"B2","to
153Oct 11 11:00:04 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Idle: Call disconnected, ts=1, flags=0000, data=85
154Oct 11 11:00:04 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 14 (New request received!): cid=86, did=87, tid=129, rid=0 , sid=0, nid=0
155Oct 11 11:00:04 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 21 (Bye Received!): cid=86, did=87, tid=129, rid=0, sid=0, nid=0
156Oct 11 11:00:04 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 16 (2xx received for request!): cid=85, did=-1, tid=128, r id=0, sid=0, nid=0
157Oct 11 11:00:04 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Call disconnected, ts=5, flags=0000, data=86
158Oct 11 11:00:04 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 5: stopping RTP stream
159Oct 11 11:00:04 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Idle: Message answered 2xx, ts=1, flags=0000, data=85
160Oct 11 11:00:08 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
161Oct 11 11:00:08 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
162Oct 11 11:00:09 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 22 (Call Context is released!): cid=85, did=0, tid=0, rid= 0, sid=0, nid=0
163
164
165Oct 11 11:00:13 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
166Oct 11 11:00:13 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
167Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Idle: CAS event, ts=1, flags=0000, data=7
168Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:275: ts 1: dialing 0
169Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: user_agent.cpp:3968: --> ua_dial_out() <sip:200@192.168.0.104> -> sip:0@192.168.0.104 ()...
170Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: CAS event, ts=1, flags=0000, data=7
171Oct 11 11:00:14 comcerto daemon.info sip_ua[462]: repro.cpp:608: doSessionAccounting(): Session Created 'branch=z9hG4bK686590916'
172Oct 11 11:00:14 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 2 (New call received!): cid=92, did=93, tid=131, rid=0, si d=0, nid=0
173Oct 11 11:00:14 comcerto daemon.info sip_ua[416]: user_agent.cpp:2354: INVITE received: sip:0@127.0.0.1:6060;transport=udp (Call-ID: 974573373@(null))
174Oct 11 11:00:14 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 5 (Call is being processed!): cid=91, did=0, tid=130, rid= 0, sid=0, nid=0
175Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: Incoming call, ts=-1, flags=0001, data=92
176Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0001, data=92
177Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Incoming call, ts=-1, flags=0001, data=92
178Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0001, data=92
179Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Idle: Incoming call, ts=-1, flags=0001, data=92
180Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Incoming call, ts=-1, flags=0001, data=92
181Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Incoming call, ts=-1, flags=0001, data=92
182Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: virtualChannel.cpp:194: ---> VirtualChannelManager: Incoming call, ts=-1, flags=0001, data=92
183Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: Incoming call, ts=-1, flags=0002, data=92
184Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0002, data=92
185Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Incoming call, ts=-1, flags=0002, data=92
186Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0002, data=92
187Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Idle: Incoming call, ts=-1, flags=0002, data=92
188Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:179: B2[5]: >>> sending message: 1 (Connect)
189Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 1 (size 3): 32 30 30
190Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 2 (size 0):
191Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: user_agent.cpp:4451: Call 92 routed to TS 5
192Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=PreAnswer: RTP monitor, ts=5, flags=0000, data=0
193Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Tone detected, ts=6, flags=0000, data=112
194Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Tone detected, ts=3, flags=0000, data=112
195Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Tone detected, ts=7, flags=0000, data=112
196Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Tone detected, ts=4, flags=0000, data=112
197Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Tone detected, ts=3, flags=0000, data=113
198Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Tone detected, ts=7, flags=0000, data=113
199Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Tone detected, ts=4, flags=0000, data=113
200Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=6, state=Idle: Tone detected, ts=6, flags=0000, data=113
201Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: DTMF detected, ts=7, flags=0000, data=15
202Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: DTMF detected, ts=3, flags=0000, data=15
203Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Any Data, ts=3, flags=0000, data=0
204Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[3]: <<< data received: b2 0b 01 01 03 32 30 30 02 00 03 01 30 00
205Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[3]: <<< received message: 1 (Connect)
206Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 1 (size 3): 32 30 30
207Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 2 (size 0):
208Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 3 (size 1): 30
209Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=7, state=Idle: Any Data, ts=7, flags=0000, data=0
210Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[7]: <<< data received: b2 0b 01 01 03 32 30 30 02 00 03 01 30 00
211Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[7]: <<< received message: 1 (Connect)
212Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 1 (size 3): 32 30 30
213Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 2 (size 0):
214Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 3 (size 1): 30
215Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=4, state=Idle: Any Data, ts=4, flags=0000, data=0
216Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:406: B2[4]: <<< data received: b2 0b 01 01 03 32 30 30 02 00 03 01 30 00
217Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[4]: <<< received message: 1 (Connect)
218Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 1 (size 3): 32 30 30
219Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 2 (size 0):
220Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 3 (size 1): 30
221Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=PreAnswer: Caller ID sending complete, ts=5, flags=0000, data=0
222Oct 11 11:00:14 comcerto daemon.info sip_ua[462]: repro.cpp:832: doSessionAccounting(): Session Established 'branch=z9hG4bK686590916'
223Oct 11 11:00:14 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 7 (Remote phone has answered!): cid=91, did=94, tid=130, r id=0, sid=0, nid=0
224Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:6263: channel 5: answer
225Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: RTP parameters, ts=5, flags=0000, data=92
226Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7099: --> ts 5: 192.168.0.104[10010] --> 192.168.0.104[10002]
227Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 5: codec PCMA, VAD is off, red=0
228Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7101: --> audio pt: 8/8, event pt: 101/101, VBD pt: -1/-1
229Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo)
230Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac
231Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 5: RTP destination is 02:ad:c3:00:01:ac
232Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 5: starting RTP stream
233Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: RTP parameters, ts=1, flags=0000, data=91
234Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7099: --> ts 1: 192.168.0.104[10002] --> 192.168.0.104[10010]
235Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 1: codec PCMA, VAD is off, red=0
236Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7101: --> audio pt: 8/8, event pt: 101/101, VBD pt: -1/-1
237Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo)
238Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac
239Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 1: RTP destination is 02:ad:c3:00:01:ac
240Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 1: starting RTP stream
241Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Calling: Call answered, ts=1, flags=0000, data=91
242Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
243Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
244Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
245Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
246Oct 11 11:00:15 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 16 (2xx received for request!): cid=88, did=90, tid=132, r id=0, sid=0, nid=0
247Oct 11 11:00:15 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 12 (ACK received!): cid=92, did=93, tid=131, rid=0, sid=0, nid=0
248Oct 11 11:00:15 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Message answered 2xx, ts=3, flags=0000, data=88
249Oct 11 11:00:15 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: ACK received, ts=5, flags=0000, data=92
250Oct 11 11:00:15 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: RTP monitor, ts=1, flags=0000, data=1
251Oct 11 11:00:15 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: RTP monitor, ts=5, flags=0000, data=1
252Oct 11 11:00:18 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
253Oct 11 11:00:18 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
254Oct 11 11:00:19 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 16 (2xx received for request!): cid=88, did=90, tid=133, r id=0, sid=0, nid=0
255Oct 11 11:00:19 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Message answered 2xx, ts=3, flags=0000, data=88
256Oct 11 11:00:19 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
257Oct 11 11:00:19 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Statistics received, ts=5, flags=0000, data=0
258Oct 11 11:00:19 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
259Oct 11 11:00:19 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
260Oct 11 11:00:23 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
261Oct 11 11:00:23 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
262Oct 11 11:00:24 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Connected: CAS event, ts=1, flags=0000, data=15
263Oct 11 11:00:24 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 1: stopping RTP stream
264Oct 11 11:00:24 comcerto daemon.info sip_ua[462]: repro.cpp:742: doSessionAccounting(): Session Ended 'branch=z9hG4bK526378332'
265Oct 11 11:00:24 comcerto daemon.info sip_ua[462]: repro.cpp:760: --> duration=10, [FXS]tel:200@192.168.0.104: ---> [B2]sip:op2@192.168.0.104:
266Oct 11 11:00:24 comcerto daemon.info sip_ua[462]: repro.cpp:1021: --> CDR: {"answer":1697022014,"duration":10,"hangup":1697022024,"org-host":"192.168.0.104"," org-scheme":"tel","org-type":"FXS","org-user":"200","to-host":"192.168.0.104","to-scheme":"sip","to-type":"B2","to
267Oct 11 11:00:24 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 14 (New request received!): cid=92, did=93, tid=135, rid=0 , sid=0, nid=0
268Oct 11 11:00:24 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 21 (Bye Received!): cid=92, did=93, tid=135, rid=0, sid=0, nid=0
269Oct 11 11:00:24 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Idle: Call disconnected, ts=1, flags=0000, data=91
270Oct 11 11:00:24 comcerto daemon.info sip_ua[391]: b2.cpp:266: ---> ts=5, state=Connected: Call disconnected, ts=5, flags=0000, data=92
271Oct 11 11:00:24 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 5: stopping RTP stream
272Oct 11 11:00:25 comcerto daemon.debug sip_ua[416]: user_agent.cpp:2216: ---> transport 0: SIP event 16 (2xx received for request!): cid=91, did=-1, tid=134, r id=0, sid=0, nid=0
273Oct 11 11:00:25 comcerto daemon.info sip_ua[391]: fxs.cpp:440: ---> ts=1, state=Idle: Message answered 2xx, ts=1, flags=0000, data=91