root@comcerto:~# logread -f Oct 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 Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: fxs.cpp:275: ts 1: dialing 0 Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: user_agent.cpp:3968: --> ua_dial_out() -> sip:0@192.168.0.104 ()... Oct 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 Oct 11 10:59:52 comcerto daemon.info sip_ua[462]: repro.cpp:608: doSessionAccounting(): Session Created 'branch=z9hG4bK1086409190' Oct 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 Oct 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)) Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: virtualChannel.cpp:194: ---> VirtualChannelManager: Incoming call, ts=-1, flags=0001, data=86 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:179: B2[5]: >>> sending message: 1 (Connect) Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 1 (size 3): 32 30 30 Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 2 (size 0): Oct 11 10:59:52 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 3 (size 1): 30 Oct 11 10:59:52 comcerto daemon.info sip_ua[391]: user_agent.cpp:4451: Call 86 routed to TS 5 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[3]: <<< received message: 1 (Connect) Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 1 (size 3): 32 30 30 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 2 (size 0): Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 3 (size 1): 30 Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: b2.cpp:147: ts 3: dialing 111@192.168.0.104 Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: user_agent.cpp:3968: --> ua_dial_out() -> sip:111@192.168.0.104 ()... Oct 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 Oct 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 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[7]: <<< received message: 1 (Connect) Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 1 (size 3): 32 30 30 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 2 (size 0): Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 3 (size 1): 30 Oct 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 Oct 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 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[4]: <<< received message: 1 (Connect) Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 1 (size 3): 32 30 30 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 2 (size 0): Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:6263: channel 5: answer Oct 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 Oct 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] Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 5: codec PCMA, VAD is off, red=0 Oct 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 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo) Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 5: RTP destination is 02:ad:c3:00:01:ac Oct 11 10:59:53 comcerto daemon.info sip_ua[462]: repro.cpp:832: doSessionAccounting(): Session Established 'branch=z9hG4bK1086409190' Oct 11 10:59:53 comcerto daemon.info sip_ua[462]: repro.cpp:608: doSessionAccounting(): Session Created 'branch=z9hG4bK997555784' Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 5: starting RTP stream Oct 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 Oct 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 Oct 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 Oct 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] Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 1: codec PCMA, VAD is off, red=0 Oct 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 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo) Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac Oct 11 10:59:53 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 1: RTP destination is 02:ad:c3:00:01:ac Oct 11 10:59:53 comcerto daemon.info sip_ua[416]: user_agent.cpp:2575: ---> ringing with status code 180 Oct 11 10:59:53 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 1: starting RTP stream Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 10:59:57 comcerto daemon.info sip_ua[462]: repro.cpp:832: doSessionAccounting(): Session Established 'branch=z9hG4bK997555784' Oct 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 Oct 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 Oct 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] Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 3: codec PCMA, VAD is off, red=0 Oct 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 Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.105 to 192.168.0.105 (eth0) Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.105): 00:15:65:a3:cf:f6 Oct 11 10:59:58 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 3: RTP destination is 00:15:65:a3:cf:f6 Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 3: starting RTP stream Oct 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 Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:179: B2[3]: >>> sending message: 1 (Connect) Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[3]: >>> parameter: 1 (size 3): 31 31 31 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[5]: <<< received message: 1 (Connect) Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[5]: <<< parameter 1 (size 3): 31 31 31 Oct 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 Oct 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 Oct 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 Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[7]: <<< received message: 1 (Connect) Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 1 (size 3): 31 31 31 Oct 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 Oct 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 Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[4]: <<< received message: 1 (Connect) Oct 11 10:59:58 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 1 (size 3): 31 31 31 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:04 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 1: stopping RTP stream Oct 11 11:00:04 comcerto daemon.info sip_ua[462]: repro.cpp:742: doSessionAccounting(): Session Ended 'branch=z9hG4bK2087124730' Oct 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: Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:04 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 5: stopping RTP stream Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: fxs.cpp:275: ts 1: dialing 0 Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: user_agent.cpp:3968: --> ua_dial_out() -> sip:0@192.168.0.104 ()... Oct 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 Oct 11 11:00:14 comcerto daemon.info sip_ua[462]: repro.cpp:608: doSessionAccounting(): Session Created 'branch=z9hG4bK686590916' Oct 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 Oct 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)) Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: virtualChannel.cpp:194: ---> VirtualChannelManager: Incoming call, ts=-1, flags=0001, data=92 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:179: B2[5]: >>> sending message: 1 (Connect) Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 1 (size 3): 32 30 30 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:193: B2[5]: >>> parameter: 2 (size 0): Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: user_agent.cpp:4451: Call 92 routed to TS 5 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[3]: <<< received message: 1 (Connect) Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 1 (size 3): 32 30 30 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 2 (size 0): Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[3]: <<< parameter 3 (size 1): 30 Oct 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 Oct 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 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[7]: <<< received message: 1 (Connect) Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 1 (size 3): 32 30 30 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 2 (size 0): Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[7]: <<< parameter 3 (size 1): 30 Oct 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 Oct 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 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:419: B2[4]: <<< received message: 1 (Connect) Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 1 (size 3): 32 30 30 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 2 (size 0): Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: b2.cpp:435: B2[4]: <<< parameter 3 (size 1): 30 Oct 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 Oct 11 11:00:14 comcerto daemon.info sip_ua[462]: repro.cpp:832: doSessionAccounting(): Session Established 'branch=z9hG4bK686590916' Oct 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 Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:6263: channel 5: answer Oct 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 Oct 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] Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 5: codec PCMA, VAD is off, red=0 Oct 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 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo) Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 5: RTP destination is 02:ad:c3:00:01:ac Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 5: starting RTP stream Oct 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 Oct 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] Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7100: --> ts 1: codec PCMA, VAD is off, red=0 Oct 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 Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7200: routing 192.168.0.104 to 192.168.0.104 (lo) Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:7211: getMac(192.168.0.104): 02:ad:c3:00:01:ac Oct 11 11:00:14 comcerto daemon.info sip_ua[391]: comcerto.cpp:7221: ts 1: RTP destination is 02:ad:c3:00:01:ac Oct 11 11:00:14 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6924: ts 1: starting RTP stream Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:24 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 1: stopping RTP stream Oct 11 11:00:24 comcerto daemon.info sip_ua[462]: repro.cpp:742: doSessionAccounting(): Session Ended 'branch=z9hG4bK526378332' Oct 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: Oct 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 Oct 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 Oct 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 Oct 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 Oct 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 Oct 11 11:00:24 comcerto daemon.debug sip_ua[391]: comcerto.cpp:6945: ts 5: stopping RTP stream Oct 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 Oct 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