2010-12-17 09:49:44.171000 [blink.exe 7440]: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x03592A10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 49, 44, 171000), modified={'logs.trace_notifications': ModifiedValue(old=False, new=True)})
2010-12-17 09:49:44.984000 [blink.exe 7440]: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x03592A10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 49, 44, 968000), modified={'logs.trace_pjsip': ModifiedValue(old=False, new=True)})
2010-12-17 09:49:59.984000 [blink.exe 7440]: Notification name=SIPEngineGotException sender=<Engine(Thread-1, started daemon 7840)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 49, 59, 953000), traceback='Traceback (most recent call last):\n  File "_core.ua.pxi", line 875, in sipsimple.core._core._PJSIPUA_cb_rx_request (sipsimple/core\\_core.c:43718)\n  File "_core.ua.pxi", line 730, in sipsimple.core._core.PJSIPUA._cb_rx_request (sipsimple/core\\_core.c:41505)\n  File "_core.invitation.pxi", line 129, in sipsimple.core._core.Invitation.init_incoming (sipsimple/core\\_core.c:92772)\n  File "_core.invitation.pxi", line 89, in sipsimple.core._core.Invitation.init_incoming (sipsimple/core\\_core.c:92161)\nPJSIPError: Could not create dialog for new INVITE session: Invalid URI (PJSIP_EINVALIDURI)\n', type=<class 'sipsimple.core._core.PJSIPError'>, value=PJSIPError('Could not create dialog for new INVITE session: Invalid URI (PJSIP_EINVALIDURI)',))
2010-12-17 09:49:59.984000 [blink.exe 7440]: Notification name=SIPEngineDidFail sender=<Engine(Thread-1, started daemon 7840)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 49, 59, 953000))
2010-12-17 09:49:59.984000 [blink.exe 7440]: Notification name=SIPApplicationDidEnd sender=<sipsimple.application.SIPApplication object at 0x01CE9130> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 49, 59, 968000), end_reason='engine failed')
2010-12-17 09:50:02.468000 [blink.exe 7440]: Notification name=SIPEngineDidEnd sender=<Engine(Thread-1, stopped daemon 7840)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 2, 468000))
2010-12-17 09:50:33.718000 [blink.exe 5536]: Notification name=SIPEngineWillStart sender=<Engine(Thread-1, initial daemon 7984)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 33, 671000))
2010-12-17 09:50:34.828000 [blink.exe 5536]: Notification name=SIPEngineDidStart sender=<Engine(Thread-1, started daemon 7984)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 33, 718000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPAccountManagerWillStart sender=<sipsimple.account.AccountManager object at 0x01D6FE50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPAccountWillActivate sender=Account('mgraves.4@pixelpower.onsip.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPAccountDidActivate sender=Account('mgraves.4@pixelpower.onsip.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPAccountWillActivate sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPAccountDidActivate sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPAccountManagerDidStart sender=<sipsimple.account.AccountManager object at 0x01D6FE50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPSessionManagerWillStart sender=<sipsimple.session.SessionManager object at 0x01D6CF10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPSessionManagerDidStart sender=<sipsimple.session.SessionManager object at 0x01D6CF10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.859000 [blink.exe 5536]: Notification name=SIPApplicationDidStart sender=<sipsimple.application.SIPApplication object at 0x01CE9130> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 859000))
2010-12-17 09:50:34.875000 [blink.exe 5536]: Notification name=BonjourAccountWillRegister sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 875000), transport='udp')
2010-12-17 09:50:34.890000 [blink.exe 5536]: Notification name=BonjourAccountWillRegister sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 890000), transport='tcp')
2010-12-17 09:50:34.906000 [blink.exe 5536]: Notification name=SIPAccountWillRegister sender=Account('mgraves.4@pixelpower.onsip.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 906000))
2010-12-17 09:50:34.921000 [blink.exe 5536]: Notification name=BonjourAccountWillInitiateDiscovery sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 921000), transport='udp')
2010-12-17 09:50:34.953000 [blink.exe 5536]: Notification name=BonjourAccountWillInitiateDiscovery sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 34, 953000), transport='tcp')
2010-12-17 09:50:35 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01DD0D90> data=TimestampedNotificationData(nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35), error=None, uri=SIPURI('pixelpower.onsip.com', None, None, 5060, False, {'transport': 'udp'}, {}), query_name='pixelpower.onsip.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x01D669F0>)
2010-12-17 09:50:35 [blink.exe 5536]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x01DD0D90> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35), result=[Route('66.227.100.25', 5060, 'udp')])
2010-12-17 09:50:35 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01D66490> data=TimestampedNotificationData(nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35), error=None, uri=SIPURI('pixelpower.onsip.com', None, None, 5060, False, {'transport': 'udp'}, {}), query_name='pixelpower.onsip.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x01D66550>)
2010-12-17 09:50:35 [blink.exe 5536]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x01D66490> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35), result=[Route('66.227.100.25', 5060, 'udp')])
2010-12-17 09:50:35.031000 [blink.exe 5536]: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x018B4C60> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35), state='SENT', prev_state='NULL')
2010-12-17 09:50:35.031000 [blink.exe 5536]: Notification name=SIPSubscriptionWillStart sender=<sipsimple.core._core.Subscription object at 0x018B4C60> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35))
2010-12-17 09:50:35.062000 [blink.exe 5536]: Notification name=SIPSubscriptionDidFail sender=<sipsimple.core._core.Subscription object at 0x018B4C60> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 62000), reason='Event Package Not Supported', code=489, min_expires=None)
2010-12-17 09:50:35.062000 [blink.exe 5536]: Notification name=SIPSubscriptionChangedState sender=<sipsimple.core._core.Subscription object at 0x018B4C60> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 62000), state='TERMINATED', prev_state='SENT')
2010-12-17 09:50:35.125000 [blink.exe 5536]: Notification name=SIPRequestDidSucceed sender=<sipsimple.core._core.Request object at 0x019C1C88> data=NotificationData(body=None, headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj0e9b956cda2b427a99e1718b770e545b'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '859f6b9e22bd4002ad05755833c1af1b'})), 'Server': FrozenHeader('Server', 'OpenSIPS (1.5.3-notls (x86_64/linux))'), 'To': FrozenToHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '75d09fb22ceadb40012c6e771a69dc74.226d'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'mokdblga', None, 4590, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:1519"', 'expires': '519'})), FrozenContactHeader(FrozenSIPURI('192.168.10.207', 'mgraves.4', None, 5060, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:18068"', 'expires': '1908'})), FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:15966"', 'expires': '600'}))], 'CSeq': (2, 'REGISTER'), 'Call-ID': FrozenHeader('Call-ID', '7b4b73e674f148898c8853391f823507')}, reason='OK', code=200, timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 125000), expires=600)
2010-12-17 09:50:35.125000 [blink.exe 5536]: Notification name=SIPRegistrationDidSucceed sender=<sipsimple.core._primitives.Registration object at 0x01D66790> data=TimestampedNotificationData(route_header=FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'hide': None, 'lr': None}), frozendict({})), None, frozendict({})), reason='OK', code=200, contact_header_list=[FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'mokdblga', None, 4590, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:1519"', 'expires': '519'})), FrozenContactHeader(FrozenSIPURI('192.168.10.207', 'mgraves.4', None, 5060, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:18068"', 'expires': '1908'})), FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:15966"', 'expires': '600'}))], timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 125000), contact_header=FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({})), expires_in=600)
2010-12-17 09:50:35.125000 [blink.exe 5536]: Notification name=SIPAccountRegistrationGotAnswer sender=Account('mgraves.4@pixelpower.onsip.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 125000), reason='OK', code=200, registrar=Route('66.227.100.25', 5060, 'udp'), registration=<sipsimple.core._primitives.Registration object at 0x01D66790>)
2010-12-17 09:50:35.125000 [blink.exe 5536]: Notification name=SIPAccountRegistrationDidSucceed sender=Account('mgraves.4@pixelpower.onsip.com') data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 125000), contact_header=FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({})), expires=600, contact_header_list=[FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'mokdblga', None, 4590, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:1519"', 'expires': '519'})), FrozenContactHeader(FrozenSIPURI('192.168.10.207', 'mgraves.4', None, 5060, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:18068"', 'expires': '1908'})), FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0', 'received': '"sip:173.11.128.197:15966"', 'expires': '600'}))], registrar=Route('66.227.100.25', 5060, 'udp'))
2010-12-17 09:50:35.171000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(service='stun', nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 171000), error=NoAnswer(), uri=SIPURI('pixelpower.onsip.com', None, None, None, False, {}, {}), query_name='_stun._udp.pixelpower.onsip.com', context='lookup_service', query_type='SRV', answer=None)
2010-12-17 09:50:35.171000 [blink.exe 5536]: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 171000), error='No stun servers found for domain pixelpower.onsip.com')
2010-12-17 09:50:35.640000 [blink.exe 5536]: Notification name=BonjourAccountRegistrationDidSucceed sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 640000), name=u'sip:hqygrsdf@192.168.10.9:4800', transport='udp')
2010-12-17 09:50:35.640000 [blink.exe 5536]: Notification name=BonjourAccountRegistrationDidSucceed sender=BonjourAccount() data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 35, 640000), name=u'sip:hqygrsdf@192.168.10.9:4803;transport=tcp', transport='tcp')
2010-12-17 09:50:44.296000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01DD0510> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 296000), consumer_slot_changed=True, old_consumer_slot=0, producer_slot_changed=False, new_consumer_slot=None)
2010-12-17 09:50:44.437000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01DD0510> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 437000), consumer_slot_changed=True, old_consumer_slot=None, producer_slot_changed=False, new_consumer_slot=0)
2010-12-17 09:50:44.453000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x035A1E10> data=TimestampedNotificationData(nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 453000), error=None, uri=SIPURI('pixelpower.onsip.com', None, None, 5060, False, {'transport': 'udp'}, {}), query_name='pixelpower.onsip.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x01D66550>)
2010-12-17 09:50:44.453000 [blink.exe 5536]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x035A1E10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 453000), result=[Route('66.227.100.25', 5060, 'udp')])
2010-12-17 09:50:44.562000 [blink.exe 5536]: Notification name=SIPSessionNewOutgoing sender=<sipsimple.session.Session object at 0x01D66BB0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 562000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x01DD0D70>])
2010-12-17 09:50:44.609000 [blink.exe 5536]: Notification name=RTPTransportDidInitialize sender=<sipsimple.core._core.RTPTransport object at 0x01DB09D0> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 593000))
2010-12-17 09:50:44.609000 [blink.exe 5536]: Notification name=MediaStreamDidInitialize sender=<sipsimple.streams.rtp.AudioStream object at 0x01DD0D70> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 609000))
2010-12-17 09:50:44.703000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C237B0> data=NotificationData(originator='local', body='', timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 687000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPj459439842d0b494eafea3dd196b379b9'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': 'd23e225519fc4a83a36b756ac1fda00f'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'lr': 1, 'hide': ''}), frozendict({})), None, frozendict({}))], 'Supported': ['100rel'], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves', None, None, 0, frozendict({}), frozendict({})), None, frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (6027, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', '5b99d2bdb41f4494bd9ded8e639c85dc'), 'Max-Forwards': 70}, state='outgoing', prev_state=None, method='INVITE', request_uri=FrozenSIPURI('pixelpower.onsip.com', 'mgraves', None, None, 0, frozendict({}), frozendict({})))
2010-12-17 09:50:44.703000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C237B0> data=NotificationData(originator='remote', body=None, code=404, disconnect_reason='user request', timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 687000), state='disconnected', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj459439842d0b494eafea3dd196b379b9'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': 'd23e225519fc4a83a36b756ac1fda00f'})), 'Server': FrozenHeader('Server', 'OpenSIPS (1.5.3-notls (x86_64/linux))'), 'To': FrozenToHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': '75d09fb22ceadb40012c6e771a69dc74.7478'})), 'CSeq': (6027, 'INVITE'), 'Call-ID': FrozenHeader('Call-ID', '5b99d2bdb41f4494bd9ded8e639c85dc')}, reason='Not Found', prev_state='outgoing')
2010-12-17 09:50:44.703000 [blink.exe 5536]: Notification name=MediaStreamWillEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01DD0D70> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 703000))
2010-12-17 09:50:44.703000 [blink.exe 5536]: Notification name=MediaStreamDidEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01DD0D70> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 703000))
2010-12-17 09:50:44.703000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x01D66BB0> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 703000), reason='Not Found', code=404, method='INVITE')
2010-12-17 09:50:44.703000 [blink.exe 5536]: Notification name=SIPSessionDidFail sender=<sipsimple.session.Session object at 0x01D66BB0> data=TimestampedNotificationData(originator='remote', reason='Not Found', code=404, timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 703000), redirect_identities=None, failure_reason='user request')
2010-12-17 09:50:44.734000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x035A1810> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 734000))
2010-12-17 09:50:44.734000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x035A1810> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 44, 734000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=1)
2010-12-17 09:50:45.312000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E80DB0> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 45, 312000))
2010-12-17 09:50:45.312000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x035A1810> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 45, 312000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:50:45.312000 [blink.exe 5536]: Notification name=WavePlayerDidEnd sender=<sipsimple.audio.WavePlayer object at 0x035A1810> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 50, 45, 312000))
2010-12-17 09:51:13.171000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01D668D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 171000), consumer_slot_changed=True, old_consumer_slot=0, producer_slot_changed=False, new_consumer_slot=None)
2010-12-17 09:51:13.203000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01D668D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 203000), consumer_slot_changed=True, old_consumer_slot=None, producer_slot_changed=False, new_consumer_slot=0)
2010-12-17 09:51:13.203000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x0359B2B0> data=TimestampedNotificationData(nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 203000), error=None, uri=SIPURI('pixelpower.onsip.com', None, None, 5060, False, {'transport': 'udp'}, {}), query_name='pixelpower.onsip.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x01D66550>)
2010-12-17 09:51:13.203000 [blink.exe 5536]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x0359B2B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 203000), result=[Route('66.227.100.25', 5060, 'udp')])
2010-12-17 09:51:13.218000 [blink.exe 5536]: Notification name=SIPSessionNewOutgoing sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 218000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x01D66990>])
2010-12-17 09:51:13.234000 [blink.exe 5536]: Notification name=RTPTransportDidInitialize sender=<sipsimple.core._core.RTPTransport object at 0x01DB0A40> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 218000))
2010-12-17 09:51:13.234000 [blink.exe 5536]: Notification name=MediaStreamDidInitialize sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 234000))
2010-12-17 09:51:13.328000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23330> data=NotificationData(originator='local', body='', timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 312000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPjbe076f118eb1422eb87f43b5d2d73cb9'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '3890e7b5da4b409bbde2818e93f8e9be'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'lr': 1, 'hide': ''}), frozendict({})), None, frozendict({}))], 'Supported': ['100rel'], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('pixelpower.onsip.com', 'mjgraves', None, None, 0, frozendict({}), frozendict({})), None, frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (467, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'a8cebd6bca4f4cc6a7af283261849c56'), 'Max-Forwards': 70}, state='outgoing', prev_state=None, method='INVITE', request_uri=FrozenSIPURI('pixelpower.onsip.com', 'mjgraves', None, None, 0, frozendict({}), frozendict({})))
2010-12-17 09:51:13.578000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23330> data=NotificationData(originator='remote', body=None, code=180, timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 562000), state='early', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPjbe076f118eb1422eb87f43b5d2d73cb9'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '3890e7b5da4b409bbde2818e93f8e9be'})), 'Accept-Language': FrozenHeader('Accept-Language', 'en'), 'Allow-Events': ['talk', 'hold', 'conference'], 'RSeq': FrozenHeader('RSeq', '8193'), 'User-Agent': FrozenHeader('User-Agent', 'PolycomSoundPointIP-SPIP_450-UA/3.2.3.1734'), 'To': FrozenToHeader(FrozenSIPURI('pixelpower.onsip.com', 'mjgraves', None, None, 0, frozendict({}), frozendict({})), 'Michael Graves', frozendict({'tag': '35DBBD90-737AB8AF'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('66.227.100.25', 'mjgraves*173.11.128.197!18068_n', None, None, 0, frozendict({'gr': ''}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (467, 'INVITE'), 'Call-ID': FrozenHeader('Call-ID', 'a8cebd6bca4f4cc6a7af283261849c56'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': 'bed.629af983', 'ftag': '3890e7b5da4b409bbde2818e93f8e9be', 'nc': '1', 'lr': 1, 'ns': '1'}), frozendict({})), None, frozendict({}))], 'Require': ['100rel']}, reason='Ringing', prev_state='outgoing')
2010-12-17 09:51:13.578000 [blink.exe 5536]: Notification name=SIPSessionGotRingIndication sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 562000))
2010-12-17 09:51:13.578000 [blink.exe 5536]: Notification name=SIPSessionGotProvisionalResponse sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 578000), reason='Ringing', code=180)
2010-12-17 09:51:13.609000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 609000))
2010-12-17 09:51:13.609000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 13, 609000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=3)
2010-12-17 09:51:14.890000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E882B0> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 14, 890000))
2010-12-17 09:51:14.906000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 14, 906000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:51:19.906000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 19, 906000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=3)
2010-12-17 09:51:21.218000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E88370> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 21, 218000))
2010-12-17 09:51:21.218000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 21, 218000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:51:23.515000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23330> data=NotificationData(originator='remote', body='v=0\r\no=- 1291643040 1291643040 IN IP4 192.168.10.207\r\ns=Polycom IP Phone\r\nc=IN IP4 192.168.10.207\r\nt=0 0\r\nm=audio 2260 RTP/AVP 9 127\r\na=sendrecv\r\na=rtpmap:9 G722/8000\r\na=rtpmap:127 telephone-event/8000\r\n', code=200, timestamp=datetime.datetime(2010, 12, 17, 9, 51, 23, 500000), state='connecting', headers={'Content-Length': 203, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPjbe076f118eb1422eb87f43b5d2d73cb9'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '3890e7b5da4b409bbde2818e93f8e9be'})), 'Accept-Language': FrozenHeader('Accept-Language', 'en'), 'Supported': ['100rel', 'replaces'], 'User-Agent': FrozenHeader('User-Agent', 'PolycomSoundPointIP-SPIP_450-UA/3.2.3.1734'), 'To': FrozenToHeader(FrozenSIPURI('pixelpower.onsip.com', 'mjgraves', None, None, 0, frozendict({}), frozendict({})), 'Michael Graves', frozendict({'tag': '35DBBD90-737AB8AF'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('66.227.100.25', 'mjgraves*173.11.128.197!18068_n', None, None, 0, frozendict({'gr': ''}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (467, 'INVITE'), 'Allow': ['INVITE', 'ACK', 'BYE', 'CANCEL', 'OPTIONS', 'INFO', 'MESSAGE', 'SUBSCRIBE', 'NOTIFY', 'PRACK', 'UPDATE', 'REFER'], 'Call-ID': FrozenHeader('Call-ID', 'a8cebd6bca4f4cc6a7af283261849c56'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': 'bed.629af983', 'ftag': '3890e7b5da4b409bbde2818e93f8e9be', 'nc': '1', 'lr': 1, 'ns': '1'}), frozendict({})), None, frozendict({}))], 'Content-Type': ('application/sdp', '')}, reason='OK', prev_state='early')
2010-12-17 09:51:23.515000 [blink.exe 5536]: Notification name=SIPInvitationGotSDPUpdate sender=<sipsimple.core._core.Invitation object at 0x01C23330> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 23, 500000), local_sdp=FrozenSDPSession('192.168.10.9', 3501568273L, 3501568273L, '-', 'IN', 'IP4', 'Blink 0.2.3 (Windows)', None, FrozenSDPConnection('192.168.10.9', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 50002, 'RTP/AVP', 1, frozenlist(['9', '101']), None, None, frozenlist([FrozenSDPAttribute('rtcp', '50003'), FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '101 telephone-event/8000'), FrozenSDPAttribute('fmtp', '101 0-15'), FrozenSDPAttribute('sendrecv', '')]))])), succeeded=True, remote_sdp=FrozenSDPSession('192.168.10.207', 1291643040L, 1291643040L, '-', 'IN', 'IP4', 'Polycom IP Phone', None, FrozenSDPConnection('192.168.10.207', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 2260, 'RTP/AVP', 0, frozenlist(['9', '127']), None, None, frozenlist([FrozenSDPAttribute('sendrecv', ''), FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '127 telephone-event/8000')]))])))
2010-12-17 09:51:23.515000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23330> data=NotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 51, 23, 500000), state='connected', prev_state='connecting', sub_state='normal')
2010-12-17 09:51:23.515000 [blink.exe 5536]: Notification name=SIPSessionWillStart sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 23, 515000))
2010-12-17 09:51:23.546000 [blink.exe 5536]: Notification name=MediaStreamDidStart sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 23, 531000))
2010-12-17 09:51:23.546000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 51, 23, 546000), reason='OK', code=200, method='INVITE')
2010-12-17 09:51:23.546000 [blink.exe 5536]: Notification name=SIPSessionDidStart sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 23, 546000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x01D66990>])
2010-12-17 09:51:32.671000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23330> data=NotificationData(originator='remote', body=None, disconnect_reason='user request', timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 656000), headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '66.227.100.25', 5060, frozendict({'received': '66.227.100.25', 'branch': 'z9hG4bKdeca.9e360df7.0'})), FrozenViaHeader('UDP', '192.168.10.207', 5060, frozendict({'received': '173.11.128.197', 'rport': 18068, 'branch': 'z9hG4bK74dd19b64977F665'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mjgraves', None, None, 0, frozendict({}), frozendict({})), 'Michael Graves', frozendict({'tag': '35DBBD90-737AB8AF'})), 'Accept-Language': FrozenHeader('Accept-Language', 'en'), 'User-Agent': FrozenHeader('User-Agent', 'PolycomSoundPointIP-SPIP_450-UA/3.2.3.1734'), 'To': FrozenToHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '3890e7b5da4b409bbde2818e93f8e9be'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('66.227.100.25', 'mjgraves*173.11.128.197!18068_n', None, None, 0, frozendict({'gr': ''}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (1, 'BYE'), 'Max-Forwards': 69, 'Call-ID': FrozenHeader('Call-ID', 'a8cebd6bca4f4cc6a7af283261849c56'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': 'bed.629af983', 'ftag': '35DBBD90-737AB8AF', 'nc': '1', 'lr': 1, 'ns': '1'}), frozendict({})), None, frozendict({}))]}, state='disconnected', prev_state='connected', method='BYE', prev_sub_state='normal', request_uri=FrozenSIPURI('173.11.128.197', 'jfrupwsa', None, 15966, 0, frozendict({}), frozendict({})))
2010-12-17 09:51:32.671000 [blink.exe 5536]: Notification name=SIPSessionWillEnd sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(originator='remote', timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 671000))
2010-12-17 09:51:32.671000 [blink.exe 5536]: Notification name=MediaStreamWillEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 671000))
2010-12-17 09:51:32.671000 [blink.exe 5536]: Notification name=MediaStreamDidEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66990> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 671000))
2010-12-17 09:51:32.687000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(originator='remote', timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 687000), reason='OK', code=200, method='BYE')
2010-12-17 09:51:32.687000 [blink.exe 5536]: Notification name=SIPSessionDidEnd sender=<sipsimple.session.Session object at 0x01D66270> data=TimestampedNotificationData(originator='remote', timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 687000), end_reason='user request')
2010-12-17 09:51:32.687000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x01D66D10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 687000))
2010-12-17 09:51:32.703000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66D10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 32, 687000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=1)
2010-12-17 09:51:33.281000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E88270> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 33, 281000))
2010-12-17 09:51:33.281000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66D10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 33, 281000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:51:33.281000 [blink.exe 5536]: Notification name=WavePlayerDidEnd sender=<sipsimple.audio.WavePlayer object at 0x01D66D10> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 33, 281000))
2010-12-17 09:51:35.406000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(service='stun', nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 51, 35, 390000), error=NoAnswer(), uri=SIPURI('pixelpower.onsip.com', None, None, None, False, {}, {}), query_name='_stun._udp.pixelpower.onsip.com', context='lookup_service', query_type='SRV', answer=None)
2010-12-17 09:51:35.406000 [blink.exe 5536]: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 51, 35, 390000), error='No stun servers found for domain pixelpower.onsip.com')
2010-12-17 09:52:35.593000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(service='stun', nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 52, 35, 593000), error=NoAnswer(), uri=SIPURI('pixelpower.onsip.com', None, None, None, False, {}, {}), query_name='_stun._udp.pixelpower.onsip.com', context='lookup_service', query_type='SRV', answer=None)
2010-12-17 09:52:35.593000 [blink.exe 5536]: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 52, 35, 593000), error='No stun servers found for domain pixelpower.onsip.com')
2010-12-17 09:53:35.781000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(service='stun', nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 53, 35, 781000), error=NoAnswer(), uri=SIPURI('pixelpower.onsip.com', None, None, None, False, {}, {}), query_name='_stun._udp.pixelpower.onsip.com', context='lookup_service', query_type='SRV', answer=None)
2010-12-17 09:53:35.781000 [blink.exe 5536]: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 35, 781000), error='No stun servers found for domain pixelpower.onsip.com')
2010-12-17 09:53:57.750000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01DAC550> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 750000), consumer_slot_changed=True, old_consumer_slot=0, producer_slot_changed=False, new_consumer_slot=None)
2010-12-17 09:53:57.796000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01DAC550> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 796000), consumer_slot_changed=True, old_consumer_slot=None, producer_slot_changed=False, new_consumer_slot=0)
2010-12-17 09:53:57.812000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01DAC3D0> data=TimestampedNotificationData(nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 812000), error=None, uri=SIPURI('pixelpower.onsip.com', None, None, 5060, False, {'transport': 'udp'}, {}), query_name='pixelpower.onsip.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x01D66550>)
2010-12-17 09:53:57.812000 [blink.exe 5536]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x01DAC3D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 812000), result=[Route('66.227.100.25', 5060, 'udp')])
2010-12-17 09:53:57.859000 [blink.exe 5536]: Notification name=SIPSessionNewOutgoing sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 859000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x01DAC3B0>])
2010-12-17 09:53:57.921000 [blink.exe 5536]: Notification name=RTPTransportDidInitialize sender=<sipsimple.core._core.RTPTransport object at 0x01DB0A40> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 875000))
2010-12-17 09:53:57.921000 [blink.exe 5536]: Notification name=MediaStreamDidInitialize sender=<sipsimple.streams.rtp.AudioStream object at 0x01DAC3B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 921000))
2010-12-17 09:53:57.984000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23870> data=NotificationData(originator='local', body='', timestamp=datetime.datetime(2010, 12, 17, 9, 53, 57, 984000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPj9c709173b65b43afa8c828e3e2780395'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '8f9c7c73cecb4c12af26748ef5428d57'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'lr': 1, 'hide': ''}), frozendict({})), None, frozendict({}))], 'Supported': ['100rel'], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', 'conference', None, None, 0, frozendict({}), frozendict({})), None, frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (32255, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'df08974ea748433f9cd121b8892de4ea'), 'Max-Forwards': 70}, state='outgoing', prev_state=None, method='INVITE', request_uri=FrozenSIPURI('sip2sip.info', 'conference', None, None, 0, frozendict({}), frozendict({})))
2010-12-17 09:53:58.187000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23870> data=NotificationData(originator='remote', body=None, code=180, timestamp=datetime.datetime(2010, 12, 17, 9, 53, 58, 187000), state='early', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj9c709173b65b43afa8c828e3e2780395'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '8f9c7c73cecb4c12af26748ef5428d57'})), 'Server': FrozenHeader('Server', 'SylkServer-1.0.0'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', 'conference', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'sbDirh4ltAIOP8t5o3NizKbwwnS3URrJ'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('81.23.228.139', 'test', None, 5060, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (32255, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'df08974ea748433f9cd121b8892de4ea'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('81.23.228.150', None, None, None, 0, frozendict({'did': '857.a5bbe9c2', 'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '857.72c6c607', 'pr': '1', 'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))]}, reason='Ringing', prev_state='outgoing')
2010-12-17 09:53:58.187000 [blink.exe 5536]: Notification name=SIPSessionGotRingIndication sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 58, 187000))
2010-12-17 09:53:58.187000 [blink.exe 5536]: Notification name=SIPSessionGotProvisionalResponse sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 58, 187000), reason='Ringing', code=180)
2010-12-17 09:53:58.187000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x0359B770> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 58, 187000))
2010-12-17 09:53:58.187000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x0359B770> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 58, 187000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=3)
2010-12-17 09:53:59.500000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E80EF0> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 59, 500000))
2010-12-17 09:53:59.500000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x0359B770> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 53, 59, 500000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:54:00.312000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23870> data=NotificationData(originator='remote', body='v=0\r\no=- 3501590039 3501590040 IN IP4 81.23.228.139\r\ns=SylkServer-1.0.0\r\nc=IN IP4 66.227.100.103\r\nt=0 0\r\nm=audio 35900 RTP/AVP 9 101\r\na=rtcp:50237\r\na=rtpmap:9 G722/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\n', code=200, timestamp=datetime.datetime(2010, 12, 17, 9, 54, 0, 281000), state='connecting', headers={'Content-Length': 234, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj9c709173b65b43afa8c828e3e2780395'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '8f9c7c73cecb4c12af26748ef5428d57'})), 'Supported': ['100rel'], 'Server': FrozenHeader('Server', 'SylkServer-1.0.0'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', 'conference', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'sbDirh4ltAIOP8t5o3NizKbwwnS3URrJ'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('81.23.228.139', 'test', None, 5060, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (32255, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'df08974ea748433f9cd121b8892de4ea'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('81.23.228.150', None, None, None, 0, frozendict({'did': '857.a5bbe9c2', 'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '857.72c6c607', 'pr': '1', 'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))], 'Content-Type': ('application/sdp', '')}, reason='OK', prev_state='early')
2010-12-17 09:54:00.312000 [blink.exe 5536]: Notification name=SIPInvitationGotSDPUpdate sender=<sipsimple.core._core.Invitation object at 0x01C23870> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 0, 281000), local_sdp=FrozenSDPSession('192.168.10.9', 3501568437L, 3501568437L, '-', 'IN', 'IP4', 'Blink 0.2.3 (Windows)', None, FrozenSDPConnection('192.168.10.9', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 50004, 'RTP/AVP', 1, frozenlist(['9', '101']), None, None, frozenlist([FrozenSDPAttribute('rtcp', '50005'), FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '101 telephone-event/8000'), FrozenSDPAttribute('fmtp', '101 0-15'), FrozenSDPAttribute('sendrecv', '')]))])), succeeded=True, remote_sdp=FrozenSDPSession('81.23.228.139', 3501590039L, 3501590040L, '-', 'IN', 'IP4', 'SylkServer-1.0.0', None, FrozenSDPConnection('66.227.100.103', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 35900, 'RTP/AVP', 0, frozenlist(['9', '101']), None, None, frozenlist([FrozenSDPAttribute('rtcp', '50237'), FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '101 telephone-event/8000'), FrozenSDPAttribute('fmtp', '101 0-15'), FrozenSDPAttribute('sendrecv', '')]))])))
2010-12-17 09:54:00.312000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23870> data=NotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 0, 296000), state='connected', prev_state='connecting', sub_state='normal')
2010-12-17 09:54:00.312000 [blink.exe 5536]: Notification name=SIPSessionWillStart sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 0, 296000))
2010-12-17 09:54:00.312000 [blink.exe 5536]: Notification name=MediaStreamDidStart sender=<sipsimple.streams.rtp.AudioStream object at 0x01DAC3B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 0, 312000))
2010-12-17 09:54:00.312000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 0, 312000), reason='OK', code=200, method='INVITE')
2010-12-17 09:54:00.312000 [blink.exe 5536]: Notification name=SIPSessionDidStart sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 0, 312000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x01DAC3B0>])
2010-12-17 09:54:13.546000 [blink.exe 5536]: Notification name=SIPSessionWillEnd sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 546000))
2010-12-17 09:54:13.546000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23870> data=NotificationData(originator='local', body=None, prev_sub_state='normal', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 546000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPj817220a57f4b41e58d1c27ed9eb42a9f'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '8f9c7c73cecb4c12af26748ef5428d57'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '857.72c6c607', 'pr': '1', 'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRouteHeader(FrozenSIPURI('81.23.228.150', None, None, None, 0, frozendict({'did': '857.a5bbe9c2', 'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'lr': 1}), frozendict({})), None, frozendict({}))], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', 'conference', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'sbDirh4ltAIOP8t5o3NizKbwwnS3URrJ'})), 'CSeq': (32256, 'BYE'), 'Call-ID': FrozenHeader('Call-ID', 'df08974ea748433f9cd121b8892de4ea'), 'Max-Forwards': 70}, state='disconnecting', prev_state='connected', method='BYE', request_uri=FrozenSIPURI('81.23.228.139', 'test', None, 5060, 0, frozendict({}), frozendict({})))
2010-12-17 09:54:13.718000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23870> data=NotificationData(originator='remote', body=None, code=200, disconnect_reason='user request', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 687000), state='disconnected', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj817220a57f4b41e58d1c27ed9eb42a9f'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '8f9c7c73cecb4c12af26748ef5428d57'})), 'Server': FrozenHeader('Server', 'SylkServer-1.0.0'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', 'conference', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'sbDirh4ltAIOP8t5o3NizKbwwnS3URrJ'})), 'CSeq': (32256, 'BYE'), 'Call-ID': FrozenHeader('Call-ID', 'df08974ea748433f9cd121b8892de4ea'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('81.23.228.150', None, None, None, 0, frozendict({'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '857.72c6c607', 'pr': '1', 'ftag': '8f9c7c73cecb4c12af26748ef5428d57', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))]}, reason='OK', prev_state='disconnecting')
2010-12-17 09:54:13.718000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 687000), reason='OK', code=200, method='BYE')
2010-12-17 09:54:13.718000 [blink.exe 5536]: Notification name=MediaStreamWillEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01DAC3B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 703000))
2010-12-17 09:54:13.718000 [blink.exe 5536]: Notification name=MediaStreamDidEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01DAC3B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 703000))
2010-12-17 09:54:13.718000 [blink.exe 5536]: Notification name=SIPSessionDidEnd sender=<sipsimple.session.Session object at 0x01DAC2F0> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 703000), end_reason='user request')
2010-12-17 09:54:13.718000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 703000))
2010-12-17 09:54:13.718000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 13, 703000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=1)
2010-12-17 09:54:14.296000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E80F70> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 14, 296000))
2010-12-17 09:54:14.296000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 14, 296000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:54:14.296000 [blink.exe 5536]: Notification name=WavePlayerDidEnd sender=<sipsimple.audio.WavePlayer object at 0x01D66F50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 14, 296000))
2010-12-17 09:54:16.750000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01D66890> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 750000), consumer_slot_changed=True, old_consumer_slot=0, producer_slot_changed=False, new_consumer_slot=None)
2010-12-17 09:54:16.796000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x01D66890> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 781000), consumer_slot_changed=True, old_consumer_slot=None, producer_slot_changed=False, new_consumer_slot=0)
2010-12-17 09:54:16.796000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x0359BF70> data=TimestampedNotificationData(nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 796000), error=None, uri=SIPURI('pixelpower.onsip.com', None, None, 5060, False, {'transport': 'udp'}, {}), query_name='pixelpower.onsip.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x01D66550>)
2010-12-17 09:54:16.796000 [blink.exe 5536]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x0359BF70> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 796000), result=[Route('66.227.100.25', 5060, 'udp')])
2010-12-17 09:54:16.828000 [blink.exe 5536]: Notification name=SIPSessionNewOutgoing sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 828000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x01D66590>])
2010-12-17 09:54:16.921000 [blink.exe 5536]: Notification name=RTPTransportDidInitialize sender=<sipsimple.core._core.RTPTransport object at 0x01DB0A40> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 843000))
2010-12-17 09:54:16.921000 [blink.exe 5536]: Notification name=MediaStreamDidInitialize sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66590> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 921000))
2010-12-17 09:54:17 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23B70> data=NotificationData(originator='local', body='', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 16, 984000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPjb44720ffa16c4784b93d035fa8ba8b4a'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '88a9874bcd8e4703ba024cc9aaa9e667'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'lr': 1, 'hide': ''}), frozendict({})), None, frozendict({}))], 'Supported': ['100rel'], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', '3333', None, None, 0, frozendict({}), frozendict({})), None, frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (29489, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'bac38028b8b34fc1b8d098d50bce5ea2'), 'Max-Forwards': 70}, state='outgoing', prev_state=None, method='INVITE', request_uri=FrozenSIPURI('sip2sip.info', '3333', None, None, 0, frozendict({}), frozendict({})))
2010-12-17 09:54:17.093000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23B70> data=NotificationData(originator='remote', body=None, code=180, timestamp=datetime.datetime(2010, 12, 17, 9, 54, 17, 93000), state='early', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPjb44720ffa16c4784b93d035fa8ba8b4a'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '88a9874bcd8e4703ba024cc9aaa9e667'})), 'Supported': ['replaces', 'timer'], 'Server': FrozenHeader('Server', 'Asterisk PBX 1.6.2.9-1'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', '3333', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'as31e23107'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('85.17.186.5', '3333', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (29489, 'INVITE'), 'Allow': ['INVITE', 'ACK', 'CANCEL', 'OPTIONS', 'BYE', 'REFER', 'SUBSCRIBE', 'NOTIFY', 'INFO'], 'Call-ID': FrozenHeader('Call-ID', 'bac38028b8b34fc1b8d098d50bce5ea2'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('85.17.186.7', None, None, None, 0, frozendict({'did': '612.628b2345', 'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '612.d3878952', 'pr': '1', 'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))]}, reason='Ringing', prev_state='outgoing')
2010-12-17 09:54:17.093000 [blink.exe 5536]: Notification name=SIPSessionGotRingIndication sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 17, 93000))
2010-12-17 09:54:17.109000 [blink.exe 5536]: Notification name=SIPSessionGotProvisionalResponse sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 17, 93000), reason='Ringing', code=180)
2010-12-17 09:54:17.109000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x035A1350> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 17, 109000))
2010-12-17 09:54:17.109000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x035A1350> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 17, 109000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=3)
2010-12-17 09:54:18.406000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E802F0> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 18, 406000))
2010-12-17 09:54:18.406000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x035A1350> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 18, 406000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:54:19.125000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23B70> data=NotificationData(originator='remote', body='v=0\r\no=root 1854484121 1854484121 IN IP4 85.17.186.5\r\ns=Asterisk PBX 1.6.2.9-1\r\nc=IN IP4 66.227.100.103\r\nt=0 0\r\nm=audio 59588 RTP/AVP 9 101\r\na=rtpmap:9 G722/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\n', code=200, timestamp=datetime.datetime(2010, 12, 17, 9, 54, 19, 109000), state='connecting', headers={'Content-Length': 266, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPjb44720ffa16c4784b93d035fa8ba8b4a'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '88a9874bcd8e4703ba024cc9aaa9e667'})), 'Supported': ['replaces', 'timer'], 'Server': FrozenHeader('Server', 'Asterisk PBX 1.6.2.9-1'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', '3333', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'as31e23107'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('85.17.186.5', '3333', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (29489, 'INVITE'), 'Allow': ['INVITE', 'ACK', 'CANCEL', 'OPTIONS', 'BYE', 'REFER', 'SUBSCRIBE', 'NOTIFY', 'INFO'], 'Call-ID': FrozenHeader('Call-ID', 'bac38028b8b34fc1b8d098d50bce5ea2'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('85.17.186.7', None, None, None, 0, frozendict({'did': '612.628b2345', 'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '612.d3878952', 'pr': '1', 'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))], 'Content-Type': ('application/sdp', '')}, reason='OK', prev_state='early')
2010-12-17 09:54:19.125000 [blink.exe 5536]: Notification name=SIPInvitationGotSDPUpdate sender=<sipsimple.core._core.Invitation object at 0x01C23B70> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 19, 109000), local_sdp=FrozenSDPSession('192.168.10.9', 3501568456L, 3501568456L, '-', 'IN', 'IP4', 'Blink 0.2.3 (Windows)', None, FrozenSDPConnection('192.168.10.9', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 50006, 'RTP/AVP', 1, frozenlist(['9', '101']), None, None, frozenlist([FrozenSDPAttribute('rtcp', '50007'), FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '101 telephone-event/8000'), FrozenSDPAttribute('fmtp', '101 0-15'), FrozenSDPAttribute('sendrecv', '')]))])), succeeded=True, remote_sdp=FrozenSDPSession('85.17.186.5', 1854484121L, 1854484121L, 'root', 'IN', 'IP4', 'Asterisk PBX 1.6.2.9-1', None, FrozenSDPConnection('66.227.100.103', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 59588, 'RTP/AVP', 0, frozenlist(['9', '101']), None, None, frozenlist([FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '101 telephone-event/8000'), FrozenSDPAttribute('fmtp', '101 0-16'), FrozenSDPAttribute('silenceSupp', 'off - - - -'), FrozenSDPAttribute('ptime', '20'), FrozenSDPAttribute('sendrecv', '')]))])))
2010-12-17 09:54:19.125000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23B70> data=NotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 19, 109000), state='connected', prev_state='connecting', sub_state='normal')
2010-12-17 09:54:19.125000 [blink.exe 5536]: Notification name=SIPSessionWillStart sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 19, 125000))
2010-12-17 09:54:19.125000 [blink.exe 5536]: Notification name=MediaStreamDidStart sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66590> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 19, 125000))
2010-12-17 09:54:19.125000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 19, 125000), reason='OK', code=200, method='INVITE')
2010-12-17 09:54:19.140000 [blink.exe 5536]: Notification name=SIPSessionDidStart sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 19, 125000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x01D66590>])
2010-12-17 09:54:23.953000 [blink.exe 5536]: Notification name=SIPSessionWillEnd sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 23, 953000))
2010-12-17 09:54:23.968000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23B70> data=NotificationData(originator='local', body=None, prev_sub_state='normal', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 23, 953000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPj0aebf5b660b94afabe2b66dc8d537670'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '88a9874bcd8e4703ba024cc9aaa9e667'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '612.d3878952', 'pr': '1', 'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRouteHeader(FrozenSIPURI('85.17.186.7', None, None, None, 0, frozendict({'did': '612.628b2345', 'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'lr': 1}), frozendict({})), None, frozendict({}))], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', '3333', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'as31e23107'})), 'CSeq': (29490, 'BYE'), 'Call-ID': FrozenHeader('Call-ID', 'bac38028b8b34fc1b8d098d50bce5ea2'), 'Max-Forwards': 70}, state='disconnecting', prev_state='connected', method='BYE', request_uri=FrozenSIPURI('85.17.186.5', '3333', None, None, 0, frozendict({}), frozendict({})))
2010-12-17 09:54:24.109000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23B70> data=NotificationData(originator='remote', body=None, code=200, disconnect_reason='user request', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 93000), state='disconnected', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj0aebf5b660b94afabe2b66dc8d537670'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '88a9874bcd8e4703ba024cc9aaa9e667'})), 'Supported': ['replaces', 'timer'], 'Server': FrozenHeader('Server', 'Asterisk PBX 1.6.2.9-1'), 'To': FrozenToHeader(FrozenSIPURI('sip2sip.info', '3333', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'as31e23107'})), 'CSeq': (29490, 'BYE'), 'Allow': ['INVITE', 'ACK', 'CANCEL', 'OPTIONS', 'BYE', 'REFER', 'SUBSCRIBE', 'NOTIFY', 'INFO'], 'Call-ID': FrozenHeader('Call-ID', 'bac38028b8b34fc1b8d098d50bce5ea2'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('85.17.186.7', None, None, None, 0, frozendict({'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'lr': 1}), frozendict({})), None, frozendict({})), FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '612.d3878952', 'pr': '1', 'ftag': '88a9874bcd8e4703ba024cc9aaa9e667', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))]}, reason='OK', prev_state='disconnecting')
2010-12-17 09:54:24.109000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 109000), reason='OK', code=200, method='BYE')
2010-12-17 09:54:24.109000 [blink.exe 5536]: Notification name=MediaStreamWillEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66590> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 109000))
2010-12-17 09:54:24.109000 [blink.exe 5536]: Notification name=MediaStreamDidEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x01D66590> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 109000))
2010-12-17 09:54:24.140000 [blink.exe 5536]: Notification name=SIPSessionDidEnd sender=<sipsimple.session.Session object at 0x01DD0B50> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 109000), end_reason='user request')
2010-12-17 09:54:24.140000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x01DA53B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 125000))
2010-12-17 09:54:24.140000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01DA53B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 125000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=1)
2010-12-17 09:54:24.718000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E80EB0> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 718000))
2010-12-17 09:54:24.718000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01DA53B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 718000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:54:24.718000 [blink.exe 5536]: Notification name=WavePlayerDidEnd sender=<sipsimple.audio.WavePlayer object at 0x01DA53B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 24, 718000))
2010-12-17 09:54:31.312000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x0359BB90> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 312000), consumer_slot_changed=True, old_consumer_slot=0, producer_slot_changed=False, new_consumer_slot=None)
2010-12-17 09:54:31.343000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x0359BB90> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 343000), consumer_slot_changed=True, old_consumer_slot=None, producer_slot_changed=False, new_consumer_slot=0)
2010-12-17 09:54:31.359000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x0359B1D0> data=TimestampedNotificationData(nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 359000), error=None, uri=SIPURI('pixelpower.onsip.com', None, None, 5060, False, {'transport': 'udp'}, {}), query_name='pixelpower.onsip.com', context='lookup_sip_proxy', query_type='A', answer=<dns.resolver.Answer object at 0x01D66550>)
2010-12-17 09:54:31.359000 [blink.exe 5536]: Notification name=DNSLookupDidSucceed sender=<sipsimple.lookup.DNSLookup object at 0x0359B1D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 359000), result=[Route('66.227.100.25', 5060, 'udp')])
2010-12-17 09:54:31.390000 [blink.exe 5536]: Notification name=SIPSessionNewOutgoing sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 390000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x0359B2B0>])
2010-12-17 09:54:31.421000 [blink.exe 5536]: Notification name=RTPTransportDidInitialize sender=<sipsimple.core._core.RTPTransport object at 0x01DB0A40> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 406000))
2010-12-17 09:54:31.421000 [blink.exe 5536]: Notification name=MediaStreamDidInitialize sender=<sipsimple.streams.rtp.AudioStream object at 0x0359B2B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 421000))
2010-12-17 09:54:31.500000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23DB0> data=NotificationData(originator='local', body='', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 484000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPj017d488e5cbf43dca84003c35606b329'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '52cdd8f343e14711a63d6e119af98f1f'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'lr': 1, 'hide': ''}), frozendict({})), None, frozendict({}))], 'Supported': ['100rel'], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('login.zipdx.com', '200901', None, None, 0, frozendict({}), frozendict({})), None, frozendict({})), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.10.9', 'jfrupwsa', None, 4800, 0, frozendict({}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (30255, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'f27b35d6977b400a851361460f1219cc'), 'Max-Forwards': 70}, state='outgoing', prev_state=None, method='INVITE', request_uri=FrozenSIPURI('login.zipdx.com', '200901', None, None, 0, frozendict({}), frozendict({})))
2010-12-17 09:54:31.609000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23DB0> data=NotificationData(originator='remote', body=None, code=180, timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 593000), state='early', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj017d488e5cbf43dca84003c35606b329'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '52cdd8f343e14711a63d6e119af98f1f'})), 'Server': FrozenHeader('Server', 'ZipDX-3.10.4'), 'To': FrozenToHeader(FrozenSIPURI('login.zipdx.com', '200901', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'tlrx-b024db-4d0b87b6'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('66.227.100.25', '*72.51.53.109', None, None, 0, frozendict({'gr': '', 'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (30255, 'INVITE'), 'Call-ID': FrozenHeader('Call-ID', 'f27b35d6977b400a851361460f1219cc'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '409.41278bf7', 'pr': '1', 'ftag': '52cdd8f343e14711a63d6e119af98f1f', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))]}, reason='Ringing', prev_state='outgoing')
2010-12-17 09:54:31.609000 [blink.exe 5536]: Notification name=SIPSessionGotRingIndication sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 609000))
2010-12-17 09:54:31.609000 [blink.exe 5536]: Notification name=SIPSessionGotProvisionalResponse sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 609000), reason='Ringing', code=180)
2010-12-17 09:54:31.609000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x01DD0DD0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 609000))
2010-12-17 09:54:31.609000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01DD0DD0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 31, 609000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=3)
2010-12-17 09:54:32.609000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23DB0> data=NotificationData(originator='remote', body='v=0\r\no=telurix 22044 3501590071 IN IP4 72.51.53.109\r\ns=-\r\nc=IN IP4 66.227.100.103\r\nt=0 0\r\nm=audio 36104 RTP/AVP 9 101\r\na=rtpmap:9 G722/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-15\r\na=ptime:20\r\n', code=200, timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 609000), state='connecting', headers={'Content-Length': 205, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj017d488e5cbf43dca84003c35606b329'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '52cdd8f343e14711a63d6e119af98f1f'})), 'Server': FrozenHeader('Server', 'ZipDX-3.10.4'), 'To': FrozenToHeader(FrozenSIPURI('login.zipdx.com', '200901', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'tlrx-b024db-4d0b87b6'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('66.227.100.25', '*72.51.53.109', None, None, 0, frozendict({'gr': '', 'transport': 'udp'}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (30255, 'INVITE'), 'Allow': ['INVITE', 'ACK', 'CANCEL', 'BYE', 'REFER', 'NOTIFY', 'OPTIONS', 'INFO', 'REGISTER', 'SUBSCRIBE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', 'f27b35d6977b400a851361460f1219cc'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '409.41278bf7', 'pr': '1', 'ftag': '52cdd8f343e14711a63d6e119af98f1f', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))], 'Content-Type': ('application/sdp', '')}, reason='Ok', prev_state='early')
2010-12-17 09:54:32.609000 [blink.exe 5536]: Notification name=SIPInvitationGotSDPUpdate sender=<sipsimple.core._core.Invitation object at 0x01C23DB0> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 609000), local_sdp=FrozenSDPSession('192.168.10.9', 3501568471L, 3501568471L, '-', 'IN', 'IP4', 'Blink 0.2.3 (Windows)', None, FrozenSDPConnection('192.168.10.9', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 50008, 'RTP/AVP', 1, frozenlist(['9', '101']), None, None, frozenlist([FrozenSDPAttribute('rtcp', '50009'), FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '101 telephone-event/8000'), FrozenSDPAttribute('fmtp', '101 0-15'), FrozenSDPAttribute('sendrecv', '')]))])), succeeded=True, remote_sdp=FrozenSDPSession('72.51.53.109', 22044L, 3501590071L, 'telurix', 'IN', 'IP4', '-', None, FrozenSDPConnection('66.227.100.103', 'IN', 'IP4'), 0, 0, frozenlist([]), frozenlist([FrozenSDPMediaStream('audio', 36104, 'RTP/AVP', 0, frozenlist(['9', '101']), None, None, frozenlist([FrozenSDPAttribute('rtpmap', '9 G722/8000'), FrozenSDPAttribute('rtpmap', '101 telephone-event/8000'), FrozenSDPAttribute('fmtp', '101 0-15'), FrozenSDPAttribute('ptime', '20')]))])))
2010-12-17 09:54:32.609000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23DB0> data=NotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 609000), state='connected', prev_state='connecting', sub_state='normal')
2010-12-17 09:54:32.609000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 609000), reason='Ok', code=200, method='INVITE')
2010-12-17 09:54:32.609000 [blink.exe 5536]: Notification name=SIPSessionWillStart sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 609000))
2010-12-17 09:54:32.625000 [blink.exe 5536]: Notification name=MediaStreamDidStart sender=<sipsimple.streams.rtp.AudioStream object at 0x0359B2B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 609000))
2010-12-17 09:54:32.625000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x01DD0DD0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 625000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:54:32.625000 [blink.exe 5536]: Notification name=WavePlayerDidEnd sender=<sipsimple.audio.WavePlayer object at 0x01DD0DD0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 625000))
2010-12-17 09:54:32.625000 [blink.exe 5536]: Notification name=SIPSessionDidStart sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 625000), streams=[<sipsimple.streams.rtp.AudioStream object at 0x0359B2B0>])
2010-12-17 09:54:32.718000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E80670> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 32, 625000))
2010-12-17 09:54:35.984000 [blink.exe 5536]: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(service='stun', nameservers=['192.168.10.1', '192.168.80.13'], timestamp=datetime.datetime(2010, 12, 17, 9, 54, 35, 968000), error=NoAnswer(), uri=SIPURI('pixelpower.onsip.com', None, None, None, False, {}, {}), query_name='_stun._udp.pixelpower.onsip.com', context='lookup_service', query_type='SRV', answer=None)
2010-12-17 09:54:35.984000 [blink.exe 5536]: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x01DD0E50> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 35, 984000), error='No stun servers found for domain pixelpower.onsip.com')
2010-12-17 09:54:36.343000 [blink.exe 5536]: Notification name=SIPSessionWillEnd sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 343000))
2010-12-17 09:54:36.453000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23DB0> data=NotificationData(originator='local', body=None, prev_sub_state='normal', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 343000), headers={'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'rport': 0, 'branch': 'z9hG4bKPj250450b71d2a4caf8885392a94997dc9'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '52cdd8f343e14711a63d6e119af98f1f'})), 'Route': [FrozenRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '409.41278bf7', 'pr': '1', 'ftag': '52cdd8f343e14711a63d6e119af98f1f', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))], 'User-Agent': FrozenHeader('User-Agent', 'Blink 0.2.3 (Windows)'), 'To': FrozenToHeader(FrozenSIPURI('login.zipdx.com', '200901', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'tlrx-b024db-4d0b87b6'})), 'CSeq': (30256, 'BYE'), 'Call-ID': FrozenHeader('Call-ID', 'f27b35d6977b400a851361460f1219cc'), 'Max-Forwards': 70}, state='disconnecting', prev_state='connected', method='BYE', request_uri=FrozenSIPURI('66.227.100.25', '*72.51.53.109', None, None, 0, frozendict({'gr': '', 'transport': 'udp'}), frozendict({})))
2010-12-17 09:54:36.515000 [blink.exe 5536]: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x01C23DB0> data=NotificationData(originator='remote', body=None, code=200, disconnect_reason='user request', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 484000), state='disconnected', headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '192.168.10.9', 4800, frozendict({'received': '173.11.128.197', 'rport': 15966, 'branch': 'z9hG4bKPj250450b71d2a4caf8885392a94997dc9'}))], 'From': FrozenFromHeader(FrozenSIPURI('pixelpower.onsip.com', 'mgraves.4', None, None, 0, frozendict({}), frozendict({})), 'mgraves.4', frozendict({'tag': '52cdd8f343e14711a63d6e119af98f1f'})), 'Server': FrozenHeader('Server', 'ZipDX-3.10.4'), 'To': FrozenToHeader(FrozenSIPURI('login.zipdx.com', '200901', None, None, 0, frozendict({}), frozendict({})), None, frozendict({'tag': 'tlrx-b024db-4d0b87b6'})), 'CSeq': (30256, 'BYE'), 'Call-ID': FrozenHeader('Call-ID', 'f27b35d6977b400a851361460f1219cc'), 'Record-Route': [FrozenRecordRouteHeader(FrozenSIPURI('66.227.100.25', None, None, None, 0, frozendict({'did': '409.41278bf7', 'pr': '1', 'ftag': '52cdd8f343e14711a63d6e119af98f1f', 'nc': '1', 'lr': 1}), frozendict({})), None, frozendict({}))]}, reason='Ok', prev_state='disconnecting')
2010-12-17 09:54:36.515000 [blink.exe 5536]: Notification name=SIPSessionDidProcessTransaction sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 484000), reason='Ok', code=200, method='BYE')
2010-12-17 09:54:36.515000 [blink.exe 5536]: Notification name=MediaStreamWillEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x0359B2B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 484000))
2010-12-17 09:54:36.515000 [blink.exe 5536]: Notification name=MediaStreamDidEnd sender=<sipsimple.streams.rtp.AudioStream object at 0x0359B2B0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 484000))
2010-12-17 09:54:36.515000 [blink.exe 5536]: Notification name=SIPSessionDidEnd sender=<sipsimple.session.Session object at 0x0359B050> data=TimestampedNotificationData(originator='local', timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 484000), end_reason='user request')
2010-12-17 09:54:36.515000 [blink.exe 5536]: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x0359B7D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 500000))
2010-12-17 09:54:36.515000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x0359B7D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 36, 500000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=1)
2010-12-17 09:54:37.093000 [blink.exe 5536]: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x01E88870> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 37, 93000))
2010-12-17 09:54:37.093000 [blink.exe 5536]: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x0359B7D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 37, 93000), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-12-17 09:54:37.093000 [blink.exe 5536]: Notification name=WavePlayerDidEnd sender=<sipsimple.audio.WavePlayer object at 0x0359B7D0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 37, 93000))
2010-12-17 09:54:42.796000 [blink.exe 5536]: Notification name=SIPEngineGotException sender=<Engine(Thread-1, started daemon 7984)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 42, 796000), traceback='Traceback (most recent call last):\n  File "_core.ua.pxi", line 875, in sipsimple.core._core._PJSIPUA_cb_rx_request (sipsimple/core\\_core.c:43718)\n  File "_core.ua.pxi", line 730, in sipsimple.core._core.PJSIPUA._cb_rx_request (sipsimple/core\\_core.c:41505)\n  File "_core.invitation.pxi", line 129, in sipsimple.core._core.Invitation.init_incoming (sipsimple/core\\_core.c:92772)\n  File "_core.invitation.pxi", line 89, in sipsimple.core._core.Invitation.init_incoming (sipsimple/core\\_core.c:92161)\nPJSIPError: Could not create dialog for new INVITE session: Invalid URI (PJSIP_EINVALIDURI)\n', type=<class 'sipsimple.core._core.PJSIPError'>, value=PJSIPError('Could not create dialog for new INVITE session: Invalid URI (PJSIP_EINVALIDURI)',))
2010-12-17 09:54:42.796000 [blink.exe 5536]: Notification name=SIPEngineDidFail sender=<Engine(Thread-1, started daemon 7984)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 42, 796000))
2010-12-17 09:54:42.812000 [blink.exe 5536]: Notification name=SIPApplicationDidEnd sender=<sipsimple.application.SIPApplication object at 0x01CE9130> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 42, 796000), end_reason='engine failed')
2010-12-17 09:54:45.500000 [blink.exe 5536]: Notification name=SIPEngineDidEnd sender=<Engine(Thread-1, stopped daemon 7984)> data=NotificationData(timestamp=datetime.datetime(2010, 12, 17, 9, 54, 45, 500000))