2010-10-25 18:14:26.881000 [Blink 8674] (5) endpoint: Request msg REGISTER/cseq=3 (tdta0x24a9000) created. 2010-10-25 18:14:26.881000 [Blink 8674] (5) tsx0x24a6464: Transaction created for Request msg REGISTER/cseq=3 (tdta0x24a9000) 2010-10-25 18:14:26.881000 [Blink 8674] (5) tsx0x24a6464: Sending Request msg REGISTER/cseq=3 (tdta0x24a9000) in state Null 2010-10-25 18:14:26.881000 [Blink 8674] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:14:26.881000 [Blink 8674] (5) tsx0x24a6464: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:14:27.381000 [Blink 8674] (5) tsx0x24a6464: Retransmit timer event 2010-10-25 18:14:27.381000 [Blink 8674] (5) tsx0x24a6464: Retransmiting Request msg REGISTER/cseq=3 (tdta0x24a9000), count=0, restart?=1 2010-10-25 18:14:28.381000 [Blink 8674] (5) tsx0x24a6464: Retransmit timer event 2010-10-25 18:14:28.381000 [Blink 8674] (5) tsx0x24a6464: Retransmiting Request msg REGISTER/cseq=3 (tdta0x24a9000), count=1, restart?=1 2010-10-25 18:14:28.881000 [Blink 8674] (5) tsx0x24a6464: Request to terminate transaction 2010-10-25 18:14:28.881000 [Blink 8674] (5) tsx0x24a6464: State changed from Calling to Terminated, event=USER 2010-10-25 18:14:28.881000 [Blink 8674] (5) tsx0x24a6464: Timeout timer event 2010-10-25 18:14:28.881000 [Blink 8674] (5) tsx0x24a6464: State changed from Terminated to Destroyed, event=TIMER 2010-10-25 18:14:28.881000 [Blink 8674] (5) tsx0x24a6464: Transaction destroyed! 2010-10-25 18:14:28.985000 [Blink 8674] (5) tdta0x24a9000: Destroying txdata Request msg REGISTER/cseq=3 (tdta0x24a9000) 2010-10-25 18:14:29.083000 [Blink 8674] (4) tcplis:55004: SIP TCP listener destroyed 2010-10-25 18:14:29.083000 [Blink 8674] (4) tls0x2252a64: SIP TLS listener destroyed 2010-10-25 18:14:29.083000 [Blink 8674] (5) sip_endpoint.c: Destroying endpoing instance.. 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_transactio: Stopping transaction layer module 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-core" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-stateful-util" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-core-events" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-invite" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-100rel" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-evsub" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-ua" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_transactio: Transaction layer module destroyed 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-tsx-layer" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-core-ua-tag" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-msg-print" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (4) sip_endpoint.c: Module "mod-core-sip-trace" unregistered 2010-10-25 18:14:29.083000 [Blink 8674] (5) sip_transport.: Destroying transport manager 2010-10-25 18:14:29.084000 [Blink 8674] (3) sip_transport.: Warning: 1 transmit buffer(s) not freed! 2010-10-25 18:14:29.084000 [Blink 8674] (4) sip_endpoint.c: Endpoint 0xb56c64 destroyed 2010-10-25 18:14:29.409000 [Blink 8674] (4) pasound.c: PortAudio sound library shutting down.. 2010-10-25 18:14:29.409000 [Blink 8674] (4) AudioMixer_370: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) AudioMixer_370: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) tdta0x238fc00: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) RTPTransport_3: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) Pool: is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) ice0x23b8600: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuntp0x2dccc2: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuntp0x2dccc2: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuntp0x2dccc2: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuntp0x179376: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuntp0x179376: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuntp0x179376: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) ice0x23b8600: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuse0xcdb800: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuse0xba3000: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuse0xba3400: Pool is not released by application, releasing now 2010-10-25 18:14:29.409000 [Blink 8674] (4) stuse0xba4000: Pool is not released by application, releasing now 2010-10-25 18:14:34.536000 [Blink 8691] (4) os_core_unix.c: pjlib 1.0.3-trunk for POSIX initialized 2010-10-25 18:14:34.592000 [Blink 8691] (4) pasound.c: PortAudio sound library initialized, status=0 2010-10-25 18:14:34.592000 [Blink 8691] (4) pasound.c: PortAudio host api count=1 2010-10-25 18:14:34.592000 [Blink 8691] (4) pasound.c: Sound device count=3 2010-10-25 18:14:34.592000 [Blink 8691] (4) pjlib: select() I/O Queue created (0x133d014) 2010-10-25 18:14:34.593000 [Blink 8691] (5) sip_endpoint.c: Creating endpoint instance... 2010-10-25 18:14:34.593000 [Blink 8691] (4) pjlib: select() I/O Queue created (0x12f9e94) 2010-10-25 18:14:34.593000 [Blink 8691] (4) sip_endpoint.c: Module "mod-msg-print" registered 2010-10-25 18:14:34.593000 [Blink 8691] (5) sip_transport.: Transport manager created. 2010-10-25 18:14:34.593000 [Blink 8691] (4) sip_endpoint.c: Module "mod-tsx-layer" registered 2010-10-25 18:14:34.593000 [Blink 8691] (4) sip_endpoint.c: Module "mod-stateful-util" registered 2010-10-25 18:14:34.593000 [Blink 8691] (4) sip_endpoint.c: Module "mod-ua" registered 2010-10-25 18:14:34.593000 [Blink 8691] (4) sip_endpoint.c: Module "mod-evsub" registered 2010-10-25 18:14:34.593000 [Blink 8691] (4) sip_endpoint.c: Module "mod-100rel" registered 2010-10-25 18:14:34.593000 [Blink 8691] (4) sip_endpoint.c: Module "mod-invite" registered 2010-10-25 18:14:34.596000 [Blink 8691] (4) sip_transport_: Error setting SO_RCVBUF: No buffer space available [120055] 2010-10-25 18:14:34.596000 [Blink 8691] (4) sip_transport_: Error setting SO_SNDBUF: No buffer space available [120055] 2010-10-25 18:14:34.596000 [Blink 8691] (4) udp0xb88800: SIP UDP transport started, published address is 10.42.43.12:49900 2010-10-25 18:14:34.597000 [Blink 8691] (4) tcplis:55021: SIP TCP listener ready for incoming connections at 10.42.43.12:55021 2010-10-25 18:14:34.599000 [Blink 8691] (5) tls0xc71864: TLS verification mode set to 0 2010-10-25 18:14:34.600000 [Blink 8691] (4) tls0xc71864: SIP TLS listener ready for incoming connections at 10.42.43.12:55022 2010-10-25 18:14:34.600000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core" registered 2010-10-25 18:14:34.600000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core-sip-trace" registered 2010-10-25 18:14:34.600000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core-ua-tag" registered 2010-10-25 18:14:34.600000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core-events" registered 2010-10-25 18:14:34.600000 [Blink 8691] (5) evsub.c: Event pkg "presence.winfo" registered by mod-core-events 2010-10-25 18:14:34.600000 [Blink 8691] (5) evsub.c: Event pkg "message-summary" registered by mod-core-events 2010-10-25 18:14:34.600000 [Blink 8691] (5) evsub.c: Event pkg "xcap-diff" registered by mod-core-events 2010-10-25 18:14:34.600000 [Blink 8691] (5) evsub.c: Event pkg "presence" registered by mod-core-events 2010-10-25 18:14:34.612000 [Blink 8691] (4) tls0xc71864: SIP TLS listener destroyed 2010-10-25 18:14:34.612000 [Blink 8691] (5) tls0x133a064: TLS verification mode set to 0 2010-10-25 18:14:34.613000 [Blink 8691] (4) tls0x133a064: SIP TLS listener ready for incoming connections at 10.42.43.12:55023 2010-10-25 18:14:34.614000 [Blink 8691] (5) conference.c: Creating conference bridge with 255 ports 2010-10-25 18:14:34.614000 [Blink 8691] (5) conference.c: Sound device successfully created for port 0 2010-10-25 18:14:34.635000 [Blink 8691] (5) pasound.c: Opened device Built-in Microphone(Core Audio)/Built-in Output(Core Audio) for recording and playback, sample rate=44100, ch=1, bits=16, 882 samples per frame, input latency=0 ms, output latency=0 ms 2010-10-25 18:14:34.635000 [Blink 8691] (5) pasound.c: Starting Built-in Microphone stream.. 2010-10-25 18:14:34.656000 [Blink 8691] (5) pasound.c: Player thread started 2010-10-25 18:14:35.164000 [Blink 8691] (5) pasound.c: Done, status=0 2010-10-25 18:14:35.165000 [Blink 8691] (5) ec0x2d2f810: Creating AEC 2010-10-25 18:14:35.165000 [Blink 8691] (4) ec0x2d2f810: AEC created, clock_rate=44100, channel=1, samples per frame=882, tail length=200 ms, latency=20 ms 2010-10-25 18:14:35.189000 [Blink 8691] (5) pasound.c: Stopping stream.. 2010-10-25 18:14:35.389000 [Blink 8691] (5) pasound.c: Done, status=0 2010-10-25 18:14:35.390000 [Blink 8691] (5) pasound.c: Closing Built-in Microphone: 0 underflow, 0 overflow 2010-10-25 18:14:35.391000 [Blink 8691] (5) conference.c: Creating conference bridge with 255 ports 2010-10-25 18:14:35.391000 [Blink 8691] (5) conference.c: Sound device successfully created for port 0 2010-10-25 18:14:35.392000 [Blink 8691] (5) pasound.c: Opened device 2: Built-in Output(Core Audio) for playing, sample rate=44100, ch=1, bits=16, 882 samples per frame, latency=0 ms 2010-10-25 18:14:35.392000 [Blink 8691] (5) pasound.c: Starting Built-in Output stream.. 2010-10-25 18:14:35.392000 [Blink 8691] (5) pasound.c: Done, status=0 2010-10-25 18:14:36.403000 [Blink 8691] (5) pasound.c: Stopping stream.. 2010-10-25 18:14:36.504000 [Blink 8691] (5) pasound.c: Done, status=0 2010-10-25 18:14:37.516000 [Blink 8691] (5) pasound.c: Closing Built-in Output: 0 underflow, 0 overflow 2010-10-25 18:14:38.544000 [Blink 8691] (5) dlg0xcfda64: UAC dialog created 2010-10-25 18:14:38.544000 [Blink 8691] (5) dlg0xcfda64: Module mod-evsub added as dialog usage, data=0xc3c3b4 2010-10-25 18:14:38.544000 [Blink 8691] (5) evsub0xcfd214: UAC subscription created, using dialog dlg0xcfda64 2010-10-25 18:14:38.544000 [Blink 8691] (5) dlg0xcfda64: Session count inc to 2 by mod-evsub 2010-10-25 18:14:38.545000 [Blink 8691] (5) endpoint: Request msg SUBSCRIBE/cseq=30452 (tdta0xcb2e00) created. 2010-10-25 18:14:38.545000 [Blink 8691] (5) dlg0xcfda64: Sending Request msg SUBSCRIBE/cseq=30452 (tdta0xcb2e00) 2010-10-25 18:14:38.545000 [Blink 8691] (5) tsx0xcb3e64: Transaction created for Request msg SUBSCRIBE/cseq=30451 (tdta0xcb2e00) 2010-10-25 18:14:38.545000 [Blink 8691] (5) tsx0xcb3e64: Sending Request msg SUBSCRIBE/cseq=30451 (tdta0xcb2e00) in state Null 2010-10-25 18:14:38.545000 [Blink 8691] (5) sip_resolve.c: Target '194.120.0.198:0' type=Unspecified resolved to '194.120.0.198:5060' type=UDP (UDP transport) 2010-10-25 18:14:38.545000 [Blink 8691] (5) tsx0xcb3e64: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:14:38.545000 [Blink 8691] (5) dlg0xcfda64: Transaction tsx0xcb3e64 state changed to Calling 2010-10-25 18:14:38.545000 [Blink 8691] (4) evsub0xcfd214: Subscription state changed NULL --> SENT 2010-10-25 18:14:38.554000 [Blink 8691] (5) endpoint: Request msg REGISTER/cseq=1 (tdta0xcb5600) created. 2010-10-25 18:14:38.554000 [Blink 8691] (5) tsx0xb68064: Transaction created for Request msg REGISTER/cseq=1 (tdta0xcb5600) 2010-10-25 18:14:38.554000 [Blink 8691] (5) tsx0xb68064: Sending Request msg REGISTER/cseq=1 (tdta0xcb5600) in state Null 2010-10-25 18:14:38.554000 [Blink 8691] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:14:38.554000 [Blink 8691] (5) tsx0xb68064: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:14:38.586000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 501/SUBSCRIBE/cseq=30451 (rdata0xb50414) 2010-10-25 18:14:38.586000 [Blink 8691] (5) tsx0xcb3e64: Incoming Response msg 501/SUBSCRIBE/cseq=30451 (rdata0xb50414) in state Calling 2010-10-25 18:14:38.586000 [Blink 8691] (5) tsx0xcb3e64: State changed from Calling to Completed, event=RX_MSG 2010-10-25 18:14:38.586000 [Blink 8691] (5) dlg0xcfda64: Received Response msg 501/SUBSCRIBE/cseq=30451 (rdata0xb50414) 2010-10-25 18:14:38.586000 [Blink 8691] (5) dlg0xcfda64: Transaction tsx0xcb3e64 state changed to Completed 2010-10-25 18:14:38.586000 [Blink 8691] (4) evsub0xcfd214: Subscription state changed SENT --> TERMINATED 2010-10-25 18:14:38.591000 [Blink 8691] (5) dlg0x1354264: UAC dialog created 2010-10-25 18:14:38.591000 [Blink 8691] (5) dlg0x1354264: Module mod-evsub added as dialog usage, data=0x134b1b4 2010-10-25 18:14:38.591000 [Blink 8691] (5) evsub0x1360614: UAC subscription created, using dialog dlg0x1354264 2010-10-25 18:14:38.591000 [Blink 8691] (5) dlg0x1354264: Session count inc to 2 by mod-evsub 2010-10-25 18:14:38.592000 [Blink 8691] (5) endpoint: Request msg SUBSCRIBE/cseq=23356 (tdta0x1390a00) created. 2010-10-25 18:14:38.592000 [Blink 8691] (5) dlg0x1354264: Sending Request msg SUBSCRIBE/cseq=23356 (tdta0x1390a00) 2010-10-25 18:14:38.592000 [Blink 8691] (5) tsx0x1354a64: Transaction created for Request msg SUBSCRIBE/cseq=23355 (tdta0x1390a00) 2010-10-25 18:14:38.592000 [Blink 8691] (5) tsx0x1354a64: Sending Request msg SUBSCRIBE/cseq=23355 (tdta0x1390a00) in state Null 2010-10-25 18:14:38.592000 [Blink 8691] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:14:38.592000 [Blink 8691] (5) tsx0x1354a64: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:14:38.592000 [Blink 8691] (5) dlg0x1354264: Transaction tsx0x1354a64 state changed to Calling 2010-10-25 18:14:38.592000 [Blink 8691] (4) evsub0x1360614: Subscription state changed NULL --> SENT 2010-10-25 18:14:38.601000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 401/REGISTER/cseq=1 (rdata0x13a7414) 2010-10-25 18:14:38.601000 [Blink 8691] (5) tsx0xb68064: Incoming Response msg 401/REGISTER/cseq=1 (rdata0x13a7414) in state Calling 2010-10-25 18:14:38.601000 [Blink 8691] (5) tsx0xb68064: State changed from Calling to Completed, event=RX_MSG 2010-10-25 18:14:38.601000 [Blink 8691] (5) tsx0xcecc64: Transaction created for Request msg REGISTER/cseq=2 (tdta0xcb5600) 2010-10-25 18:14:38.601000 [Blink 8691] (5) tsx0xcecc64: Sending Request msg REGISTER/cseq=2 (tdta0xcb5600) in state Null 2010-10-25 18:14:38.601000 [Blink 8691] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:14:38.601000 [Blink 8691] (5) tsx0xcecc64: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:14:38.638000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 501/SUBSCRIBE/cseq=23355 (rdata0xb50414) 2010-10-25 18:14:38.638000 [Blink 8691] (5) tsx0x1354a64: Incoming Response msg 501/SUBSCRIBE/cseq=23355 (rdata0xb50414) in state Calling 2010-10-25 18:14:38.638000 [Blink 8691] (5) tsx0x1354a64: State changed from Calling to Completed, event=RX_MSG 2010-10-25 18:14:38.638000 [Blink 8691] (5) dlg0x1354264: Received Response msg 501/SUBSCRIBE/cseq=23355 (rdata0xb50414) 2010-10-25 18:14:38.638000 [Blink 8691] (5) dlg0x1354264: Transaction tsx0x1354a64 state changed to Completed 2010-10-25 18:14:38.638000 [Blink 8691] (4) evsub0x1360614: Subscription state changed SENT --> TERMINATED 2010-10-25 18:14:38.647000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 100/REGISTER/cseq=2 (rdata0xb50414) 2010-10-25 18:14:38.647000 [Blink 8691] (5) tsx0xcecc64: Incoming Response msg 100/REGISTER/cseq=2 (rdata0xb50414) in state Calling 2010-10-25 18:14:38.647000 [Blink 8691] (5) tsx0xcecc64: State changed from Calling to Proceeding, event=RX_MSG 2010-10-25 18:14:38.652000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 200/REGISTER/cseq=2 (rdata0x13a7414) 2010-10-25 18:14:38.652000 [Blink 8691] (5) tsx0xcecc64: Incoming Response msg 200/REGISTER/cseq=2 (rdata0x13a7414) in state Proceeding 2010-10-25 18:14:38.652000 [Blink 8691] (5) tsx0xcecc64: State changed from Proceeding to Completed, event=RX_MSG 2010-10-25 18:14:43.586000 [Blink 8691] (5) tsx0xcb3e64: Timeout timer event 2010-10-25 18:14:43.586000 [Blink 8691] (5) tsx0xcb3e64: State changed from Completed to Terminated, event=TIMER 2010-10-25 18:14:43.586000 [Blink 8691] (5) dlg0xcfda64: Transaction tsx0xcb3e64 state changed to Terminated 2010-10-25 18:14:43.586000 [Blink 8691] (4) evsub0xcfd214: Subscription destroyed 2010-10-25 18:14:43.586000 [Blink 8691] (5) dlg0xcfda64: Session count dec to 1 by mod-evsub 2010-10-25 18:14:43.586000 [Blink 8691] (5) dlg0xcfda64: Dialog destroyed 2010-10-25 18:14:43.586000 [Blink 8691] (5) tsx0xcb3e64: Timeout timer event 2010-10-25 18:14:43.586000 [Blink 8691] (5) tsx0xcb3e64: State changed from Terminated to Destroyed, event=TIMER 2010-10-25 18:14:43.586000 [Blink 8691] (5) tdta0xcb2e00: Destroying txdata Request msg SUBSCRIBE/cseq=30451 (tdta0xcb2e00) 2010-10-25 18:14:43.586000 [Blink 8691] (5) tsx0xcb3e64: Transaction destroyed! 2010-10-25 18:14:43.602000 [Blink 8691] (5) tsx0xb68064: Timeout timer event 2010-10-25 18:14:43.602000 [Blink 8691] (5) tsx0xb68064: State changed from Completed to Terminated, event=TIMER 2010-10-25 18:14:43.604000 [Blink 8691] (5) tsx0xb68064: Timeout timer event 2010-10-25 18:14:43.604000 [Blink 8691] (5) tsx0xb68064: State changed from Terminated to Destroyed, event=TIMER 2010-10-25 18:14:43.604000 [Blink 8691] (5) tsx0xb68064: Transaction destroyed! 2010-10-25 18:14:43.639000 [Blink 8691] (5) tsx0x1354a64: Timeout timer event 2010-10-25 18:14:43.639000 [Blink 8691] (5) tsx0x1354a64: State changed from Completed to Terminated, event=TIMER 2010-10-25 18:14:43.639000 [Blink 8691] (5) dlg0x1354264: Transaction tsx0x1354a64 state changed to Terminated 2010-10-25 18:14:43.639000 [Blink 8691] (4) evsub0x1360614: Subscription destroyed 2010-10-25 18:14:43.639000 [Blink 8691] (5) dlg0x1354264: Session count dec to 1 by mod-evsub 2010-10-25 18:14:43.639000 [Blink 8691] (5) dlg0x1354264: Dialog destroyed 2010-10-25 18:14:43.639000 [Blink 8691] (5) tsx0x1354a64: Timeout timer event 2010-10-25 18:14:43.639000 [Blink 8691] (5) tsx0x1354a64: State changed from Terminated to Destroyed, event=TIMER 2010-10-25 18:14:43.639000 [Blink 8691] (5) tdta0x1390a00: Destroying txdata Request msg SUBSCRIBE/cseq=23355 (tdta0x1390a00) 2010-10-25 18:14:43.639000 [Blink 8691] (5) tsx0x1354a64: Transaction destroyed! 2010-10-25 18:14:43.653000 [Blink 8691] (5) tsx0xcecc64: Timeout timer event 2010-10-25 18:14:43.653000 [Blink 8691] (5) tsx0xcecc64: State changed from Completed to Terminated, event=TIMER 2010-10-25 18:14:43.653000 [Blink 8691] (5) tsx0xcecc64: Timeout timer event 2010-10-25 18:14:43.653000 [Blink 8691] (5) tsx0xcecc64: State changed from Terminated to Destroyed, event=TIMER 2010-10-25 18:14:43.653000 [Blink 8691] (5) tsx0xcecc64: Transaction destroyed! 2010-10-25 18:14:48.893000 [Blink 8691] (5) pasound.c: Opened device Built-in Microphone(Core Audio)/Built-in Output(Core Audio) for recording and playback, sample rate=44100, ch=1, bits=16, 882 samples per frame, input latency=0 ms, output latency=0 ms 2010-10-25 18:14:48.893000 [Blink 8691] (5) pasound.c: Starting Built-in Microphone stream.. 2010-10-25 18:14:48.894000 [Blink 8691] (5) pasound.c: Done, status=0 2010-10-25 18:14:48.894000 [Blink 8691] (5) ec0x179bf8f0: Creating AEC 2010-10-25 18:14:48.894000 [Blink 8691] (4) ec0x179bf8f0: AEC created, clock_rate=44100, channel=1, samples per frame=882, tail length=200 ms, latency=20 ms 2010-10-25 18:14:48.895000 [Blink 8691] (4) conference.c: Port 2 (mixer-port) transmitting to port 0 (Master/sound) 2010-10-25 18:14:48.895000 [Blink 8691] (4) conference.c: Port 0 (Master/sound) transmitting to port 1 (mixer-port) 2010-10-25 18:14:48.912000 [Blink 8691] (5) pasound.c: Player thread started 2010-10-25 18:14:48.912000 [Blink 8691] (4) Master/sound: Underflow, buf_cnt=0, will generate 1 frame 2010-10-25 18:14:48.914000 [Blink 8691] (5) pasound.c: Recorder thread started 2010-10-25 18:14:48.914000 [Blink 8691] (5) ec0x179bf8f0: Prefetching.. 2010-10-25 18:14:48.930000 [Blink 8691] (5) ec0x179bf8f0: Latency bufferring complete 2010-10-25 18:14:49.114000 [Blink 8691] (4) Master/sound: Underflow, buf_cnt=0, will generate 1 frame 2010-10-25 18:14:49.788000 [Blink 8691] (4) ice0x1446a00: Creating ICE stream transport with 2 component(s) 2010-10-25 18:14:49.789000 [Blink 8691] (4) ice0x1446a00: Comp 1: host candidate 10.42.43.12:53865 added 2010-10-25 18:14:49.789000 [Blink 8691] (4) ice0x1446a00: Comp 1: host candidate 10.211.55.2:53865 added 2010-10-25 18:14:49.789000 [Blink 8691] (4) ice0x1446a00: Comp 1: host candidate 10.37.129.2:53865 added 2010-10-25 18:14:49.790000 [Blink 8691] (4) ice0x1446a00: Comp 2: host candidate 10.42.43.12:57274 added 2010-10-25 18:14:49.790000 [Blink 8691] (4) ice0x1446a00: Comp 2: host candidate 10.211.55.2:57274 added 2010-10-25 18:14:49.790000 [Blink 8691] (4) ice0x1446a00: Comp 2: host candidate 10.37.129.2:57274 added 2010-10-25 18:14:49.790000 [Blink 8691] (4) ice0x1446a00: ICE stream transport created 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: ICE session created, comp_cnt=2, role is Controlling agent 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: ICE nomination type set to regular 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: Candidate 0 added: comp_id=1, type=host, foundation=Ha2a2b0c, addr=10.42.43.12:53865, base=10.42.43.12:53865, prio=0x7effffff (2130706431) 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: Candidate 1 added: comp_id=1, type=host, foundation=Had33702, addr=10.211.55.2:53865, base=10.211.55.2:53865, prio=0x7effffff (2130706431) 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: Candidate 2 added: comp_id=1, type=host, foundation=Ha258102, addr=10.37.129.2:53865, base=10.37.129.2:53865, prio=0x7effffff (2130706431) 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: Candidate 3 added: comp_id=2, type=host, foundation=Ha2a2b0c, addr=10.42.43.12:57274, base=10.42.43.12:57274, prio=0x7efffffe (2130706430) 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: Candidate 4 added: comp_id=2, type=host, foundation=Had33702, addr=10.211.55.2:57274, base=10.211.55.2:57274, prio=0x7efffffe (2130706430) 2010-10-25 18:14:49.887000 [Blink 8691] (4) ice0x1446a00: Candidate 5 added: comp_id=2, type=host, foundation=Ha258102, addr=10.37.129.2:57274, base=10.37.129.2:57274, prio=0x7efffffe (2130706430) 2010-10-25 18:14:49.888000 [Blink 8691] (5) dlg0xd0ca64: UAC dialog created 2010-10-25 18:14:49.888000 [Blink 8691] (5) dlg0xd0ca64: Module mod-invite added as dialog usage, data=0xd0d214 2010-10-25 18:14:49.888000 [Blink 8691] (5) dlg0xd0ca64: Session count inc to 3 by mod-invite 2010-10-25 18:14:49.888000 [Blink 8691] (5) dlg0xd0ca64: Module mod-100rel added as dialog usage, data=0xd70710 2010-10-25 18:14:49.888000 [Blink 8691] (5) dlg0xd0ca64: 100rel module attached 2010-10-25 18:14:49.888000 [Blink 8691] (5) inv0xd0ca64: UAC invite session created for dialog dlg0xd0ca64 2010-10-25 18:14:49.889000 [Blink 8691] (5) endpoint: Request msg INVITE/cseq=23695 (tdta0xd7ea00) created. 2010-10-25 18:14:49.889000 [Blink 8691] (5) inv0xd0ca64: Sending Request msg INVITE/cseq=23695 (tdta0xd7ea00) 2010-10-25 18:14:49.889000 [Blink 8691] (5) dlg0xd0ca64: Sending Request msg INVITE/cseq=23695 (tdta0xd7ea00) 2010-10-25 18:14:49.889000 [Blink 8691] (5) tsx0xd70a64: Transaction created for Request msg INVITE/cseq=23694 (tdta0xd7ea00) 2010-10-25 18:14:49.889000 [Blink 8691] (5) tsx0xd70a64: Sending Request msg INVITE/cseq=23694 (tdta0xd7ea00) in state Null 2010-10-25 18:14:49.889000 [Blink 8691] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:14:49.889000 [Blink 8691] (5) tsx0xd70a64: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:14:49.889000 [Blink 8691] (5) dlg0xd0ca64: Transaction tsx0xd70a64 state changed to Calling 2010-10-25 18:14:49.937000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 401/INVITE/cseq=23694 (rdata0xb50414) 2010-10-25 18:14:49.937000 [Blink 8691] (5) tsx0xd70a64: Incoming Response msg 401/INVITE/cseq=23694 (rdata0xb50414) in state Calling 2010-10-25 18:14:49.937000 [Blink 8691] (5) endpoint: Request msg ACK/cseq=23694 (tdta0xd48200) created. 2010-10-25 18:14:49.937000 [Blink 8691] (5) tsx0xd70a64: State changed from Calling to Completed, event=RX_MSG 2010-10-25 18:14:49.937000 [Blink 8691] (5) dlg0xd0ca64: Received Response msg 401/INVITE/cseq=23694 (rdata0xb50414) 2010-10-25 18:14:49.937000 [Blink 8691] (5) dlg0xd0ca64: Transaction tsx0xd70a64 state changed to Completed 2010-10-25 18:14:49.937000 [Blink 8691] (5) inv0xd0ca64: Sending Request msg INVITE/cseq=23694 (tdta0xd7ea00) 2010-10-25 18:14:49.937000 [Blink 8691] (5) dlg0xd0ca64: Sending Request msg INVITE/cseq=23694 (tdta0xd7ea00) 2010-10-25 18:14:49.937000 [Blink 8691] (5) tsx0xd59c64: Transaction created for Request msg INVITE/cseq=23695 (tdta0xd7ea00) 2010-10-25 18:14:49.937000 [Blink 8691] (5) tsx0xd59c64: Sending Request msg INVITE/cseq=23695 (tdta0xd7ea00) in state Null 2010-10-25 18:14:49.937000 [Blink 8691] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:14:49.937000 [Blink 8691] (5) tsx0xd59c64: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:14:49.937000 [Blink 8691] (5) dlg0xd0ca64: Transaction tsx0xd59c64 state changed to Calling 2010-10-25 18:14:50.437000 [Blink 8691] (5) tsx0xd59c64: Retransmit timer event 2010-10-25 18:14:50.437000 [Blink 8691] (5) tsx0xd59c64: Retransmiting Request msg INVITE/cseq=23695 (tdta0xd7ea00), count=0, restart?=1 2010-10-25 18:14:51.437000 [Blink 8691] (5) tsx0xd59c64: Retransmit timer event 2010-10-25 18:14:51.437000 [Blink 8691] (5) tsx0xd59c64: Retransmiting Request msg INVITE/cseq=23695 (tdta0xd7ea00), count=1, restart?=1 2010-10-25 18:14:53.437000 [Blink 8691] (5) tsx0xd59c64: Retransmit timer event 2010-10-25 18:14:53.437000 [Blink 8691] (5) tsx0xd59c64: Retransmiting Request msg INVITE/cseq=23695 (tdta0xd7ea00), count=2, restart?=1 2010-10-25 18:14:53.909000 [Blink 8691] (4) sound_port.c: EC suspended because of inactivity 2010-10-25 18:14:57.437000 [Blink 8691] (5) tsx0xd59c64: Retransmit timer event 2010-10-25 18:14:57.437000 [Blink 8691] (5) tsx0xd59c64: Retransmiting Request msg INVITE/cseq=23695 (tdta0xd7ea00), count=3, restart?=1 2010-10-25 18:15:05.437000 [Blink 8691] (5) tsx0xd59c64: Retransmit timer event 2010-10-25 18:15:05.437000 [Blink 8691] (5) tsx0xd59c64: Retransmiting Request msg INVITE/cseq=23695 (tdta0xd7ea00), count=4, restart?=1 2010-10-25 18:15:21.437000 [Blink 8691] (5) tsx0xd59c64: Retransmit timer event 2010-10-25 18:15:21.437000 [Blink 8691] (5) tsx0xd59c64: Retransmiting Request msg INVITE/cseq=23695 (tdta0xd7ea00), count=5, restart?=1 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd70a64: Timeout timer event 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd70a64: State changed from Completed to Terminated, event=TIMER 2010-10-25 18:15:21.937000 [Blink 8691] (5) dlg0xd0ca64: Transaction tsx0xd70a64 state changed to Terminated 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd59c64: Timeout timer event 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd59c64: State changed from Calling to Terminated, event=TIMER 2010-10-25 18:15:21.937000 [Blink 8691] (5) dlg0xd0ca64: Transaction tsx0xd59c64 state changed to Terminated 2010-10-25 18:15:21.937000 [Blink 8691] (5) dlg0xd0ca64: Session count dec to 1 by mod-invite 2010-10-25 18:15:21.937000 [Blink 8691] (5) dlg0xd0ca64: Dialog destroyed 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd70a64: Timeout timer event 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd70a64: State changed from Terminated to Destroyed, event=TIMER 2010-10-25 18:15:21.937000 [Blink 8691] (5) tdta0xd48200: Destroying txdata Request msg ACK/cseq=23694 (tdta0xd48200) 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd70a64: Transaction destroyed! 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd59c64: Timeout timer event 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd59c64: State changed from Terminated to Destroyed, event=TIMER 2010-10-25 18:15:21.937000 [Blink 8691] (5) tdta0xd7ea00: Destroying txdata Request msg INVITE/cseq=23695 (tdta0xd7ea00) 2010-10-25 18:15:21.937000 [Blink 8691] (5) tsx0xd59c64: Transaction destroyed! 2010-10-25 18:15:22.045000 [Blink 8691] (4) wav_player.c: File player '/Applications/Communications/Blink.app/Contents/Resources/hangup_tone.wav' created: samp.rate=32000, ch=1, bufsize=4KB, filesize=32KB 2010-10-25 18:15:22.045000 [Blink 8691] (5) resample.c: resample created: high qualiy, large filter, in/out rate=32000/44100 2010-10-25 18:15:22.045000 [Blink 8691] (5) resample.c: resample created: high qualiy, large filter, in/out rate=44100/32000 2010-10-25 18:15:22.045000 [Blink 8691] (4) conference.c: Port 1 (/Applications/Communications/Blink.app/Contents/Resources/hangup_tone.wav) transmitting to port 0 (Master/sound) 2010-10-25 18:15:22.059000 [Blink 8691] (4) sound_port.c: EC activated 2010-10-25 18:15:22.555000 [Blink 8691] (5) wav_player.c: File port /Applications/Communications/Blink.app/Contents/Resources/hangup_tone.wav EOF 2010-10-25 18:15:22.575000 [Blink 8691] (5) wav_player.c: File port /Applications/Communications/Blink.app/Contents/Resources/hangup_tone.wav EOF 2010-10-25 18:15:22.611000 [Blink 8691] (5) wav_player.c: File port /Applications/Communications/Blink.app/Contents/Resources/hangup_tone.wav EOF 2010-10-25 18:15:22.629000 [Blink 8691] (5) wav_player.c: File port /Applications/Communications/Blink.app/Contents/Resources/hangup_tone.wav EOF 2010-10-25 18:15:22.655000 [Blink 8691] (5) pasound.c: Stopping stream.. 2010-10-25 18:15:22.883000 [Blink 8691] (5) pasound.c: Done, status=0 2010-10-25 18:15:22.884000 [Blink 8691] (5) pasound.c: Closing Built-in Microphone: 0 underflow, 0 overflow 2010-10-25 18:15:25.877000 [Blink 8691] (5) endpoint: Request msg REGISTER/cseq=3 (tdta0x1398600) created. 2010-10-25 18:15:25.877000 [Blink 8691] (5) tsx0x13ac664: Transaction created for Request msg REGISTER/cseq=3 (tdta0x1398600) 2010-10-25 18:15:25.877000 [Blink 8691] (5) tsx0x13ac664: Sending Request msg REGISTER/cseq=3 (tdta0x1398600) in state Null 2010-10-25 18:15:25.877000 [Blink 8691] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:15:25.877000 [Blink 8691] (5) tsx0x13ac664: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:15:25.922000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 401/REGISTER/cseq=3 (rdata0x1470614) 2010-10-25 18:15:25.923000 [Blink 8691] (5) tsx0x13ac664: Incoming Response msg 401/REGISTER/cseq=3 (rdata0x1470614) in state Calling 2010-10-25 18:15:25.923000 [Blink 8691] (5) tsx0x13ac664: State changed from Calling to Completed, event=RX_MSG 2010-10-25 18:15:25.923000 [Blink 8691] (5) tsx0x1280a64: Transaction created for Request msg REGISTER/cseq=4 (tdta0x1398600) 2010-10-25 18:15:25.923000 [Blink 8691] (5) tsx0x1280a64: Sending Request msg REGISTER/cseq=4 (tdta0x1398600) in state Null 2010-10-25 18:15:25.923000 [Blink 8691] (5) sip_resolve.c: Target '77.72.169.134:0' type=Unspecified resolved to '77.72.169.134:5060' type=UDP (UDP transport) 2010-10-25 18:15:25.923000 [Blink 8691] (5) tsx0x1280a64: State changed from Null to Calling, event=TX_MSG 2010-10-25 18:15:25.973000 [Blink 8691] (5) sip_endpoint.c: Processing incoming message: Response msg 200/REGISTER/cseq=4 (rdata0x1470614) 2010-10-25 18:15:25.973000 [Blink 8691] (5) tsx0x1280a64: Incoming Response msg 200/REGISTER/cseq=4 (rdata0x1470614) in state Calling 2010-10-25 18:15:25.973000 [Blink 8691] (5) tsx0x1280a64: State changed from Calling to Completed, event=RX_MSG 2010-10-25 18:15:26.078000 [Blink 8691] (4) tcplis:55021: SIP TCP listener destroyed 2010-10-25 18:15:26.078000 [Blink 8691] (4) tls0x133a064: SIP TLS listener destroyed 2010-10-25 18:15:26.078000 [Blink 8691] (5) sip_endpoint.c: Destroying endpoing instance.. 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_transactio: Stopping transaction layer module 2010-10-25 18:15:26.078000 [Blink 8691] (5) tsx0x1280a64: Request to terminate transaction 2010-10-25 18:15:26.078000 [Blink 8691] (5) tsx0x1280a64: State changed from Completed to Terminated, event=USER 2010-10-25 18:15:26.078000 [Blink 8691] (5) tsx0x1280a64: Transaction destroyed! 2010-10-25 18:15:26.078000 [Blink 8691] (5) tsx0x13ac664: Request to terminate transaction 2010-10-25 18:15:26.078000 [Blink 8691] (5) tsx0x13ac664: State changed from Completed to Terminated, event=USER 2010-10-25 18:15:26.078000 [Blink 8691] (5) tdta0x1398600: Destroying txdata Request msg REGISTER/cseq=4 (tdta0x1398600) 2010-10-25 18:15:26.078000 [Blink 8691] (5) tsx0x13ac664: Transaction destroyed! 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-stateful-util" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core-events" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-invite" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-100rel" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-evsub" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-ua" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_transactio: Transaction layer module destroyed 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-tsx-layer" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core-ua-tag" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-msg-print" unregistered 2010-10-25 18:15:26.078000 [Blink 8691] (4) sip_endpoint.c: Module "mod-core-sip-trace" unregistered 2010-10-25 18:15:26.079000 [Blink 8691] (5) sip_transport.: Destroying transport manager 2010-10-25 18:15:26.080000 [Blink 8691] (3) sip_transport.: Warning: 1 transmit buffer(s) not freed! 2010-10-25 18:15:26.080000 [Blink 8691] (4) sip_endpoint.c: Endpoint 0x1268464 destroyed 2010-10-25 18:15:26.101000 [Blink 8691] (4) pasound.c: PortAudio sound library shutting down.. 2010-10-25 18:15:26.101000 [Blink 8691] (4) AudioMixer_546: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) AudioMixer_369: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) tdta0xcb5600: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) RTPTransport_3: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) Pool: is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) ice0x1446a00: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuntp0x371bd1: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuntp0x371bd1: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuntp0x371bd1: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuntp0x1782d2: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuntp0x1782d2: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuntp0x1782d2: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) ice0x1446a00: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuse0xd6da00: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuse0xd6e600: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuse0xd6ea00: Pool is not released by application, releasing now 2010-10-25 18:15:26.101000 [Blink 8691] (4) stuse0xd6f600: Pool is not released by application, releasing now