2010-10-25 18:14:21.068804: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x1607b990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 21, 60924), modified={'logs.trace_notifications': ModifiedValue(old=False, new=True)})
2010-10-25 18:14:21.565603: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x1607b990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 21, 551061), modified={'logs.trace_pjsip': ModifiedValue(old=False, new=True)})
2010-10-25 18:14:23.364149: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x1607b990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 23, 352800), modified={'logs.trace_sip': ModifiedValue(old=False, new=True)})
2010-10-25 18:14:24.061657: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x1607b990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 24, 43047), modified={'logs.trace_xcap': ModifiedValue(old=False, new=True)})
2010-10-25 18:14:25.424245: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x1607b990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 25, 415571), modified={'logs.directory': ModifiedValue(old=UserDataPath('logs'), new=UserDataPath('logs'))})
2010-10-25 18:14:26.884092: Notification name=SIPApplicationWillEnd sender=<sipsimple.application.SIPApplication object at 0x1607b050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 26, 875426))
2010-10-25 18:14:26.884234: Notification name=SIPAccountManagerWillEnd sender=<sipsimple.account.AccountManager object at 0x1607b690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 26, 876717))
2010-10-25 18:14:26.884353: Notification name=SIPSessionManagerWillEnd sender=<sipsimple.session.SessionManager object at 0x1610fa10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 26, 877131))
2010-10-25 18:14:26.884497: Notification name=SIPSessionManagerDidEnd sender=<sipsimple.session.SessionManager object at 0x1610fa10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 26, 879494))
2010-10-25 18:14:26.884615: Notification name=BonjourAccountRegistrationDidEnd sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 26, 880575))
2010-10-25 18:14:26.884750: Notification name=SIPRegistrationWillEnd sender=<sipsimple.core._primitives.Registration object at 0x16179190> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 26, 880934))
2010-10-25 18:14:26.884867: Notification name=SIPAccountDidDeactivate sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 26, 882024))
2010-10-25 18:14:28.984461: Notification name=SIPRequestDidFail sender=<sipsimple.core._core.Request object at 0x174c03e0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 28, 881594), reason='Request Timeout', code=408)
2010-10-25 18:14:28.984609: Notification name=SIPRegistrationDidNotEnd sender=<sipsimple.core._primitives.Registration object at 0x16179190> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 28, 982373), reason='Request Timeout', code=408)
2010-10-25 18:14:28.984745: Notification name=SIPRequestDidEnd sender=<sipsimple.core._core.Request object at 0x174c03e0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 28, 881603))
2010-10-25 18:14:28.986016: Notification name=SIPAccountRegistrationDidNotEnd sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 28, 983464), reason='Request Timeout', code=408, registration=<sipsimple.core._primitives.Registration object at 0x16179190>)
2010-10-25 18:14:28.986168: Notification name=SIPAccountDidDeactivate sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 28, 984916))
2010-10-25 18:14:28.991232: Notification name=SIPAccountManagerDidEnd sender=<sipsimple.account.AccountManager object at 0x1607b690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 28, 989702))
2010-10-25 18:14:29.412951: Notification name=SIPEngineWillEnd sender=<Engine(Thread-1, started daemon)> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 29, 83397))
2010-10-25 18:14:29.418908: Notification name=SIPEngineDidEnd sender=<Engine(Thread-1, stopped daemon)> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 29, 414101))
2010-10-25 18:14:29.420861: Notification name=SIPApplicationDidEnd sender=<sipsimple.application.SIPApplication object at 0x1607b050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 29, 420592), end_reason='application request')
2010-10-25 18:14:34.611796: Notification name=SIPEngineWillStart sender=<Engine(Thread-1, started daemon)> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 34, 535966))
2010-10-25 18:14:34.614218: Notification name=SIPEngineDidStart sender=<Engine(Thread-1, started daemon)> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 34, 612242))
2010-10-25 18:14:37.520290: Notification name=SIPAccountManagerWillStart sender=<sipsimple.account.AccountManager object at 0x15f79690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 518128))
2010-10-25 18:14:37.520454: Notification name=SIPAccountDidActivate sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 519317))
2010-10-25 18:14:37.526667: Notification name=SIPAccountDidActivate sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 522668))
2010-10-25 18:14:37.535079: Notification name=SIPAccountManagerDidStart sender=<sipsimple.account.AccountManager object at 0x15f79690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 534803))
2010-10-25 18:14:37.537195: Notification name=SIPSessionManagerWillStart sender=<sipsimple.session.SessionManager object at 0x1603a7f0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 536899))
2010-10-25 18:14:37.537948: Notification name=SIPSessionManagerDidStart sender=<sipsimple.session.SessionManager object at 0x1603a7f0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 537690))
2010-10-25 18:14:37.541205: Notification name=SIPApplicationDidStart sender=<sipsimple.application.SIPApplication object at 0x15f79050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 540405))
2010-10-25 18:14:37.567028: Notification name=SIPAccountWillRegister sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 566110))
2010-10-25 18:14:37.572286: Notification name=BonjourAccountWillRegister sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 566647))
2010-10-25 18:14:37.606381: Notification name=BonjourAccountWillRestartDiscovery sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 37, 605948))
2010-10-25 18:14:38.047321: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x16083e10> data=TimestampedNotificationData(service='stun', timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 45776), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}), query_name='_stun._udp.sip.voipcheap.com', context='lookup_service', query_type='SRV', answer=None)
2010-10-25 18:14:38.047521: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x16083e10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 46797), error='No stun servers found for domain sip.voipcheap.com')
2010-10-25 18:14:38.057883: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x16098890> data=TimestampedNotificationData(service='stun', timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 57377), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}), query_name='_stun._udp.sip.voipcheap.com', context='lookup_service', query_type='SRV', answer=None)
2010-10-25 18:14:38.058328: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x16098890> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 58015), error='No stun servers found for domain sip.voipcheap.com')
2010-10-25 18:14:38.059443: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x160982d0> data=TimestampedNotificationData(query_name='sip.voipcheap.com', context='lookup_sip_proxy', query_type='NAPTR', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 59175), error=NoAnswer(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.062757: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x16098390> data=TimestampedNotificationData(query_name='sip.voipcheap.com', context='lookup_sip_proxy', query_type='NAPTR', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 60883), error=NoAnswer(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.193760: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x16098390> data=TimestampedNotificationData(query_name='_sips._tcp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 191727), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.199200: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x160982d0> data=TimestampedNotificationData(query_name='_sips._tcp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 198738), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.313552: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x16098390> data=TimestampedNotificationData(query_name='_sip._tcp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 311858), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.324858: Notification name=BonjourAccountRegistrationDidSucceed sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 323787), name=u'sip:drskeyow@10.42.43.12:49900')
2010-10-25 18:14:38.333079: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x160982d0> data=TimestampedNotificationData(query_name='_sip._tcp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 331683), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.473842: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x16098390> data=TimestampedNotificationData(query_name='_sip._udp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 473329), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.486809: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x160982d0> data=TimestampedNotificationData(query_name='_sip._udp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 485227), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.546315: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x16098390> data=TimestampedNotificationData(query_name='sip.voipcheap.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x1609d170>, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 543624), error=None, uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.546531: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x16098390> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 544017), result=[Route('194.120.0.198', 5060, 'udp'), Route('77.72.169.134', 5060, 'udp')])
2010-10-25 18:14:38.553484: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x160982d0> data=TimestampedNotificationData(query_name='sip.voipcheap.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x1609d110>, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 552936), error=None, uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}))
2010-10-25 18:14:38.554985: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x160982d0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 553598), result=[Route('77.72.169.134', 5060, 'udp'), Route('194.120.0.198', 5060, 'udp')])
2010-10-25 18:14:38.595699: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x548b6c0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 545210), state='SENT', prev_state='NULL')
2010-10-25 18:14:38.595857: Notification name=SIPSubscriptionWillStart sender=<sipsimple.core._core.Subscription object at 0x548b6c0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 545218))
2010-10-25 18:14:38.597324: Notification name=SIPSubscriptionDidFail sender=<sipsimple.core._core.Subscription object at 0x548b6c0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 586595), reason='Not implemented', code=501, min_expires=None)
2010-10-25 18:14:38.597443: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x548b6c0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 586600), state='TERMINATED', prev_state='SENT')
2010-10-25 18:14:38.606412: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x548b7b0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 592194), state='SENT', prev_state='NULL')
2010-10-25 18:14:38.606531: Notification name=SIPSubscriptionWillStart sender=<sipsimple.core._core.Subscription object at 0x548b7b0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 592219))
2010-10-25 18:14:38.642821: Notification name=SIPSubscriptionDidFail sender=<sipsimple.core._core.Subscription object at 0x548b7b0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 638972), reason='Not implemented', code=501, min_expires=None)
2010-10-25 18:14:38.642946: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x548b7b0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 638977), state='TERMINATED', prev_state='SENT')
2010-10-25 18:14:38.649284: Notification name=SIPRequestGotProvisionalResponse sender=<sipsimple.core._core.Request object at 0x31c7fa0> data=NotificationData(body=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 647595), reason='Trying', code=100, headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '10.42.43.12', 49900, frozendict({'rport': 0, 'branch': 'z9hG4bKPj0aC0IayOuBsj6OnnAdNfSiqmN2fklIUd'}))], 'From': FrozenFromHeader(FrozenSIPURI('sip.voipcheap.com', 'skypenet_ru', None, None, 0, frozendict({}), frozendict({})), 'skypenet_ru', frozendict({'tag': 'mH9HyzCGagJd.S.JdQvJ36f0Zfky7tyo'})), 'Server': FrozenHeader('Server', '(Very nice Sip Registrar/Proxy Server)'), 'To': FrozenToHeader(FrozenSIPURI('sip.voipcheap.com', 'skypenet_ru', None, None, 0, frozendict({}), frozendict({})), 'skypenet_ru', frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('77.72.169.134', None, None, 5060, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (2, 'REGISTER'), 'Allow': ['ACK', 'BYE', 'CANCEL', 'INVITE', 'REGISTER', 'OPTIONS', 'INFO', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', '52eXGJjMJb4jdRXl4HMLxJ.h7sSc410a')})
2010-10-25 18:14:38.655447: Notification name=SIPRequestDidSucceed sender=<sipsimple.core._core.Request object at 0x31c7fa0> data=NotificationData(body=None, headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '10.42.43.12', 49900, frozendict({'rport': 0, 'branch': 'z9hG4bKPj0aC0IayOuBsj6OnnAdNfSiqmN2fklIUd'}))], 'From': FrozenFromHeader(FrozenSIPURI('sip.voipcheap.com', 'skypenet_ru', None, None, 0, frozendict({}), frozendict({})), 'skypenet_ru', frozendict({'tag': 'mH9HyzCGagJd.S.JdQvJ36f0Zfky7tyo'})), 'Server': FrozenHeader('Server', '(Very nice Sip Registrar/Proxy Server)'), 'To': FrozenToHeader(FrozenSIPURI('sip.voipcheap.com', 'skypenet_ru', None, None, 0, frozendict({}), frozendict({})), 'skypenet_ru', frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.42.43.12', 'wxfeblnp', None, 49900, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'expires': '600'}))], 'CSeq': (2, 'REGISTER'), 'Allow': ['ACK', 'BYE', 'CANCEL', 'INVITE', 'REGISTER', 'OPTIONS', 'INFO', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', '52eXGJjMJb4jdRXl4HMLxJ.h7sSc410a')}, reason='Ok', code=200, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 653112), expires=600)
2010-10-25 18:14:38.655935: Notification name=SIPRegistrationDidSucceed sender=<sipsimple.core._primitives.Registration object at 0x160981f0> data=TimestampedNotificationData(route_header=FrozenRouteHeader(FrozenSIPURI('77.72.169.134', None, None, None, 0, frozendict({'hide': None, 'lr': None}), frozendict({})), None, frozendict({})), reason='Ok', code=200, contact_header_list=[FrozenContactHeader(FrozenSIPURI('10.42.43.12', 'wxfeblnp', None, 49900, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'expires': '600'}))], timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 654166), contact_header=FrozenContactHeader(FrozenSIPURI('10.42.43.12', 'wxfeblnp', None, 49900, 0, frozendict({}), frozendict({})), None, frozendict({})), expires_in=600)
2010-10-25 18:14:38.656128: Notification name=SIPAccountRegistrationGotAnswer sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 655628), reason='Ok', code=200, registrar=Route('77.72.169.134', 5060, 'udp'), registration=<sipsimple.core._primitives.Registration object at 0x160981f0>)
2010-10-25 18:14:38.656721: Notification name=SIPAccountRegistrationDidSucceed sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 38, 656272), contact_header=FrozenContactHeader(FrozenSIPURI('10.42.43.12', 'wxfeblnp', None, 49900, 0, frozendict({}), frozendict({})), None, frozendict({})), expires=600, contact_header_list=[FrozenContactHeader(FrozenSIPURI('10.42.43.12', 'wxfeblnp', None, 49900, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'expires': '600'}))], registrar=Route('77.72.169.134', 5060, 'udp'))
2010-10-25 18:14:49.031156: Notification name=BlinkStreamHandlerChangedState sender=<AudioController: 0x1738e850> data={'detail': None, 'state': 'WAITING_DNS_LOOKUP'}
2010-10-25 18:14:49.037599: Notification name=BlinkSessionChangedState sender=<SessionController: 0x2d473c0> data={'reason': None, 'state': 'DNS_LOOKUP'}
2010-10-25 18:14:49.110750: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x1609d9d0> data=TimestampedNotificationData(query_name='sip.voipcheap.com', context='lookup_sip_proxy', query_type='NAPTR', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 107243), error=NoAnswer(), uri=SIPURI('sip.voipcheap.com', '+74955056362', None, None, False, {}, {}))
2010-10-25 18:14:49.166702: Notification name=ITunesPauseDidExecute sender=<interfaces.itunes.ITunesInterface object at 0x1775f450> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 166289))
2010-10-25 18:14:49.253828: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x1609d9d0> data=TimestampedNotificationData(query_name='_sips._tcp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 251441), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', '+74955056362', None, None, False, {}, {}))
2010-10-25 18:14:49.397889: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x1609d9d0> data=TimestampedNotificationData(query_name='_sip._tcp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 395474), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', '+74955056362', None, None, False, {}, {}))
2010-10-25 18:14:49.556931: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x1609d9d0> data=TimestampedNotificationData(query_name='_sip._udp.sip.voipcheap.com', context='lookup_sip_proxy', query_type='SRV', answer=None, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 556471), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', '+74955056362', None, None, False, {}, {}))
2010-10-25 18:14:49.587358: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x1609d9d0> data=TimestampedNotificationData(query_name='sip.voipcheap.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x1609d110>, timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 586225), error=None, uri=SIPURI('sip.voipcheap.com', '+74955056362', None, None, False, {}, {}))
2010-10-25 18:14:49.587502: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x1609d9d0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 586651), result=[Route('77.72.169.134', 5060, 'udp'), Route('194.120.0.198', 5060, 'udp')])
2010-10-25 18:14:49.596588: Notification name=SIPSessionNewOutgoing sender=<sipsimple.session.Session object at 0x1609db50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 592257), streams=[<sipsimple.streams.rtp.AudioStream object at 0x1609dbd0>])
2010-10-25 18:14:49.603503: Notification name=BlinkSessionChangedState sender=<SessionController: 0x2d473c0> data={'reason': None, 'state': 'CONNECTING'}
2010-10-25 18:14:49.787684: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x1775fef0> data=TimestampedNotificationData(service='stun', timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 787026), error=NXDOMAIN(), uri=SIPURI('sip.voipcheap.com', None, None, None, False, {}, {}), query_name='_stun._udp.sip.voipcheap.com', context='lookup_service', query_type='SRV', answer=None)
2010-10-25 18:14:49.788236: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x1775fef0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 787838), error='No stun servers found for domain sip.voipcheap.com')
2010-10-25 18:14:49.890080: Notification name=RTPTransportICENegotiationStateDidChange sender=<sipsimple.core._core.RTPTransport object at 0x1607bf10> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 788621), state='ICE Candidates Gathering')
2010-10-25 18:14:49.890220: Notification name=AudioStreamICENegotiationStateDidChange sender=<sipsimple.streams.rtp.AudioStream object at 0x1609dbd0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 788621), state='ICE Candidates Gathering')
2010-10-25 18:14:49.891204: Notification name=RTPTransportDidInitialize sender=<sipsimple.core._core.RTPTransport object at 0x1607bf10> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 790402))
2010-10-25 18:14:49.891321: Notification name=MediaStreamDidInitialize sender=<sipsimple.streams.rtp.AudioStream object at 0x1609dbd0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 887368))
2010-10-25 18:14:49.941416: Notification name=RTPTransportICENegotiationStateDidChange sender=<sipsimple.core._core.RTPTransport object at 0x1607bf10> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 887146), state='ICE Session Initialized')
2010-10-25 18:14:49.941563: Notification name=AudioStreamICENegotiationStateDidChange sender=<sipsimple.streams.rtp.AudioStream object at 0x1609dbd0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 887146), state='ICE Session Initialized')
2010-10-25 18:14:49.951712: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x5494930> data=NotificationData(originator='local', body='', timestamp=datetime.datetime(2010, 10, 25, 18, 14, 49, 938086), headers={'Via': [FrozenViaHeader('UDP', '10.42.43.12', 49900, frozendict({'rport': 0, 'branch': 'z9hG4bKPjcYgEUlzD7SjT3h85fzQaWjbu5uClj6iu'}))], 'From': FrozenFromHeader(FrozenSIPURI('sip.voipcheap.com', 'skypenet_ru', None, None, 0, frozendict({}), frozendict({})), 'skypenet_ru', frozendict({'tag': 'CfBXQ43Na4BvSpurP-cvJSlhfrL.D1lN'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('77.72.169.134', None, None, None, 0, frozendict({'lr': 1, 'hide': ''}), frozendict({})), None, frozendict({}))], 'Supported': ['100rel'], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.20.2 (MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('sip.voipcheap.com', '+74955056362', None, None, 0, frozendict({}), frozendict({})), None, frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.42.43.12', 'wxfeblnp', None, 49900, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (23694, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'tc-p2sitKpaCZcHXz54dSHe5ALioH8Hr'), 'Max-Forwards': 70}, state='outgoing', prev_state=None, method='INVITE', request_uri=FrozenSIPURI('sip.voipcheap.com', '+74955056362', None, None, 0, frozendict({}), frozendict({})))
2010-10-25 18:15:22.042202: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x5494930> data=NotificationData(originator='local', disconnect_reason='timeout', state='disconnected', prev_state='outgoing', timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 37401))
2010-10-25 18:15:22.046226: Notification name=MediaStreamWillEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x1609dbd0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 42649))
2010-10-25 18:15:22.046376: Notification name=MediaStreamDidEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x1609dbd0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 43141))
2010-10-25 18:15:22.046526: Notification name=SIPSessionDidFail sender=<sipsimple.session.Session object at 0x1609db50> data=TimestampedNotificationData(originator='local', reason=None, code=0, timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 43773), redirect_identities=None, failure_reason='timeout')
2010-10-25 18:15:22.046667: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x16083b10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 45515))
2010-10-25 18:15:22.046813: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x16083b10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 45746), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=1)
2010-10-25 18:15:22.051532: Notification name=BlinkStreamHandlerChangedState sender=<AudioController: 0x1738e850> data={'detail': 'Audio removed', 'state': 'IDLE'}
2010-10-25 18:15:22.065382: Notification name=BlinkStreamHandlerChangedState sender=<AudioController: 0x1738e850> data={'detail': u'timeout', 'state': 'FAILED'}
2010-10-25 18:15:22.065594: Notification name=BlinkSessionChangedState sender=<SessionController: 0x2d473c0> data={'reason': u'timeout', 'state': 'FAILED'}
2010-10-25 18:15:22.644846: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x16099430> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 642281))
2010-10-25 18:15:22.645075: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x16083b10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 643820), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-10-25 18:15:22.645228: Notification name=WavePlayerDidEnd sender=<sipsimple.audio.WavePlayer object at 0x16083b10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 22, 644626))
2010-10-25 18:15:25.874001: Notification name=SIPApplicationWillEnd sender=<sipsimple.application.SIPApplication object at 0x15f79050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 873422))
2010-10-25 18:15:25.874968: Notification name=SIPAccountManagerWillEnd sender=<sipsimple.account.AccountManager object at 0x15f79690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 874698))
2010-10-25 18:15:25.878736: Notification name=SIPSessionManagerWillEnd sender=<sipsimple.session.SessionManager object at 0x1603a7f0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 875431))
2010-10-25 18:15:25.878868: Notification name=SIPSessionManagerDidEnd sender=<sipsimple.session.SessionManager object at 0x1603a7f0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 875647))
2010-10-25 18:15:25.879135: Notification name=BonjourAccountRegistrationDidEnd sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 876612))
2010-10-25 18:15:25.879411: Notification name=SIPRegistrationWillEnd sender=<sipsimple.core._primitives.Registration object at 0x160981f0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 876913))
2010-10-25 18:15:25.879683: Notification name=SIPAccountDidDeactivate sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 877539))
2010-10-25 18:15:25.976309: Notification name=SIPRequestDidSucceed sender=<sipsimple.core._core.Request object at 0x17971240> data=NotificationData(body=None, headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '10.42.43.12', 49900, frozendict({'rport': 0, 'branch': 'z9hG4bKPj2JqTu3G68OdYse5p5MeuI3F0WdPjTVvr'}))], 'From': FrozenFromHeader(FrozenSIPURI('sip.voipcheap.com', 'skypenet_ru', None, None, 0, frozendict({}), frozendict({})), 'skypenet_ru', frozendict({'tag': 'Gzs9vhffBb8zQF9vS6FmdbE5yyNL6BFf'})), 'Server': FrozenHeader('Server', '(Very nice Sip Registrar/Proxy Server)'), 'To': FrozenToHeader(FrozenSIPURI('sip.voipcheap.com', 'skypenet_ru', None, None, 0, frozendict({}), frozendict({})), 'skypenet_ru', frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('10.42.43.12', 'wxfeblnp', None, 49900, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (4, 'REGISTER'), 'Allow': ['ACK', 'BYE', 'CANCEL', 'INVITE', 'REGISTER', 'OPTIONS', 'INFO', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', '52eXGJjMJb4jdRXl4HMLxJ.h7sSc410a')}, reason='Ok', code=200, timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 973283), expires=0)
2010-10-25 18:15:25.976489: Notification name=SIPRegistrationDidEnd sender=<sipsimple.core._primitives.Registration object at 0x160981f0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 974656), expired=False)
2010-10-25 18:15:25.976645: Notification name=SIPAccountRegistrationDidEnd sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 975167), registration=<sipsimple.core._primitives.Registration object at 0x160981f0>)
2010-10-25 18:15:25.976927: Notification name=SIPRequestDidEnd sender=<sipsimple.core._core.Request object at 0x17971240> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 973287))
2010-10-25 18:15:25.978607: Notification name=SIPAccountDidDeactivate sender=Account('skypenet_ru@sip.voipcheap.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 977921))
2010-10-25 18:15:25.983677: Notification name=SIPAccountManagerDidEnd sender=<sipsimple.account.AccountManager object at 0x15f79690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 982176))
2010-10-25 18:15:26.020303: Notification name=ITunesResumeDidExecute sender=<interfaces.itunes.ITunesInterface object at 0x1775f450> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 26, 19350))
2010-10-25 18:15:26.020439: Notification name=ITunesResumeDidExecute sender=<interfaces.itunes.ITunesInterface object at 0x1775f450> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 26, 19791))
2010-10-25 18:15:26.078121: Notification name=SIPRequestDidEnd sender=<sipsimple.core._core.Request object at 0x31c7fa0> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 25, 974646))
2010-10-25 18:15:26.109564: Notification name=SIPEngineWillEnd sender=<Engine(Thread-1, stopped daemon)> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 26, 78454))
2010-10-25 18:15:26.113983: Notification name=SIPEngineDidEnd sender=<Engine(Thread-1, stopped daemon)> data=NotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 26, 106358))
2010-10-25 18:15:26.114374: Notification name=SIPApplicationDidEnd sender=<sipsimple.application.SIPApplication object at 0x15f79050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 10, 25, 18, 15, 26, 114086), end_reason='application request')