2010-09-14 10:22:01.209251: Notification name=CFGSettingsObjectDidChange sender=<sipsimple.configuration.settings.SIPSimpleSettings object at 0x15f96ed0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 1, 207533), modified={'logs.trace_notifications': ModifiedValue(old=False, new=True)})
2010-09-14 10:22:09.827461: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x18c53290> data=TimestampedNotificationData(service='stun', timestamp=datetime.datetime(2010, 9, 14, 10, 22, 9, 824801), error=Timeout(), uri=SIPURI('sip2sip.info', None, None, None, False, {}, {}), query_name='_stun._udp.sip2sip.info', context='lookup_service', query_type='SRV', answer=None)
2010-09-14 10:22:09.827672: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x18c53290> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 9, 826322), error='Timeout in lookup for stun servers for domain sip2sip.info')
2010-09-14 10:22:24.886246: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x472a630> data=NotificationData(originator='remote', body='v=0\r\no=Sonus_UAC 2828 22509 IN IP4 64.190.127.132\r\ns=SIP Media Capabilities\r\ne=unknown@invalid.net\r\nt=0 0\r\nm=audio 40070 RTP/AVP 0 8 18 101\r\nc=IN IP4 64.190.127.132\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:18 G729/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:18 annexb=no\r\na=fmtp:101 0-15\r\na=maxptime:20\r\na=sendrecv\r\n', timestamp=datetime.datetime(2010, 9, 14, 10, 22, 24, 879294), headers={'x-nt-location': FrozenHeader('x-nt-location', '523'), 'Content-Length': 333, 'Via': [FrozenViaHeader('UDP', '64.190.127.4', 5060, frozendict({'received': '64.190.127.4', 'branch': 'z9hG4bK-186d930-f6c06512-45eaca84'}))], 'From': FrozenFromHeader(FrozenSIPURI('starpoint.com', '15512210650', None, 5060, 0, frozendict({'user': 'phone'}), frozendict({})), 'WIRELESS CALLER', frozendict({'tag': 'c4-45026-c1cfca-4594aed8-c1cfca'})), 'Privacy': FrozenHeader('Privacy', 'none'), 'Supported': ['com.nortelnetworks.firewall', 'p-3rdpartycontrol', 'nosec', 'join', 'com.nortelnetworks.im.encryption'], 'Diversion': FrozenHeader('Diversion', '<sip:2122380851@10.126.4.144;user=phone>;reason=unconditional;counter=1;privacy=off'), 'User-Agent': FrozenHeader('User-Agent', 'CS2000_NGSS/9.0'), 'To': FrozenToHeader(FrozenSIPURI('starpoint.com', '2122380851', None, 5060, 0, frozendict({}), frozendict({})), 'Tony Nelson', frozendict({})), 'Remote-Party-ID': FrozenHeader('Remote-Party-ID', '<sip:2122380851@10.126.4.144;user=phone>;party=called;reason=unconditional;counter=1;privacy=off'), 'Contact': [FrozenContactHeader(FrozenSIPURI('64.190.127.4', None, None, 5060, 0, frozendict({'nt_end_pt': 'YM0+~K12.183a4814W~KE0C2~Bhrensvos.~LAUG~LnirPQGRelF!c~P6hU00qblLSJA~Nv2scid~N4S9T17G890.-kS0e1wt3mO!Pcaf513e9otDGlZ-1dnUSe_igeZFAikO-NP82', 'nt_server_host': '64.190.127.4'}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (1, 'INVITE'), 'Allow': ['ACK', 'REFER'], 'Max-Forwards': 39, 'x-nt-corr-id': FrozenHeader('x-nt-corr-id', '05910a01b2fd42e3de1be4b5d1ab3d0d7c7013@64.190.127.4'), 'Call-ID': FrozenHeader('Call-ID', '15910a01b2113c693de1be43ea86b36b5d02db7@64.190.127.4'), 'Content-Type': ('application/sdp', '')}, state='incoming', prev_state=None, method='INVITE', request_uri=FrozenSIPURI('192.168.38.68', 'xwdmnbic', None, 12693, 0, frozendict({'maddr': '64.190.10.2'}), frozendict({})))
2010-09-14 10:22:24.887966: Notification name=SIPSessionNewIncoming sender=<sipsimple.session.Session object at 0x18f6ce30> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 24, 886821), streams=[<sipsimple.streams.rtp.AudioStream object at 0x18f709f0>])
2010-09-14 10:22:24.913827: Notification name=WavePlayerDidStart sender=<sipsimple.audio.WavePlayer object at 0x18c4a690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 24, 913493))
2010-09-14 10:22:24.915396: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x18c4a690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 24, 914483), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=5)
2010-09-14 10:22:25.021149: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x472a630> data=NotificationData(originator='local', body=None, code=180, timestamp=datetime.datetime(2010, 9, 14, 10, 22, 25, 10890), state='early', headers={'Via': [FrozenViaHeader('UDP', '64.190.127.4', 5060, frozendict({'received': '64.190.127.4', 'branch': 'z9hG4bK-186d930-f6c06512-45eaca84'}))], 'From': FrozenFromHeader(FrozenSIPURI('starpoint.com', '15512210650', None, 5060, 0, frozendict({'user': 'phone'}), frozendict({})), 'WIRELESS CALLER', frozendict({'tag': 'c4-45026-c1cfca-4594aed8-c1cfca'})), 'Server': FrozenHeader('Server', 'Blink 0.20.1 (MacOSX)'), 'To': FrozenToHeader(FrozenSIPURI('starpoint.com', '2122380851', None, 5060, 0, frozendict({}), frozendict({})), 'Tony Nelson', frozendict({'tag': 'TPsFLeW5as6PXCDcCrwox6F2fd76Bg2p'})), 'Contact': [FrozenContactHeader(FrozenSIPURI('192.168.38.68', 'xwdmnbic', None, 12693, 0, frozendict({'maddr': '64.190.10.2'}), frozendict({})), None, frozendict({'q': '0.0'}))], 'CSeq': (1, 'INVITE'), 'Allow': ['SUBSCRIBE', 'NOTIFY', 'PRACK', 'INVITE', 'ACK', 'BYE', 'CANCEL', 'UPDATE', 'MESSAGE'], 'Call-ID': FrozenHeader('Call-ID', '15910a01b2113c693de1be43ea86b36b5d02db7@64.190.127.4')}, reason='Ringing', prev_state='incoming')
2010-09-14 10:22:25.038607: Notification name=ITunesPauseDidExecute sender=<interfaces.itunes.ITunesInterface object at 0x18c6ed70> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 25, 36766))
2010-09-14 10:22:26.217759: Notification name=WaveFileDidFinishPlaying sender=<sipsimple.core._core.WaveFile object at 0x18f61170> data=NotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 26, 216803))
2010-09-14 10:22:26.218790: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.WavePlayer object at 0x18c4a690> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 26, 218261), old_producer_slot=None, consumer_slot_changed=False, producer_slot_changed=True, new_producer_slot=None)
2010-09-14 10:22:31.127302: Notification name=AudioPortDidChangeSlots sender=<sipsimple.audio.AudioDevice object at 0x18c66a90> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 31, 124439), consumer_slot_changed=True, old_consumer_slot=0, producer_slot_changed=False, new_consumer_slot=None)
2010-09-14 10:22:31.128321: Notification name=BlinkStreamHandlerChangedState sender=<AudioController: 0x1608e600> data={'detail': None, 'state': 'INCOMING'}
2010-09-14 10:22:31.137374: Notification name=BlinkStreamHandlerChangedState sender=<AudioController: 0x2e91600> data={'detail': None, 'state': 'INCOMING'}
2010-09-14 10:22:31.227369: Notification name=RTPTransportDidInitialize sender=<sipsimple.core._core.RTPTransport object at 0x18f27ea0> data=NotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 31, 138320))
2010-09-14 10:22:31.228863: Notification name=MediaStreamDidInitialize sender=<sipsimple.streams.rtp.AudioStream object at 0x18f709f0> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 22, 31, 228325))
2010-09-14 10:22:43.518655: Notification name=SIPInvitationChangedState sender=<sipsimple.core._core.Invitation object at 0x472a630> data=NotificationData(originator='remote', body=None, disconnect_reason='user request', timestamp=datetime.datetime(2010, 9, 14, 10, 22, 43, 511100), headers={'Content-Length': 0, 'Via': [FrozenViaHeader('UDP', '64.190.127.4', 5060, frozendict({'received': '64.190.127.4', 'branch': 'z9hG4bK-186d930-f6c06512-45eaca84'}))], 'From': FrozenFromHeader(FrozenSIPURI('starpoint.com', '15512210650', None, 5060, 0, frozendict({'user': 'phone'}), frozendict({})), 'WIRELESS CALLER', frozendict({'tag': 'c4-45026-c1cfca-4594aed8-c1cfca'})), 'To': FrozenToHeader(FrozenSIPURI('starpoint.com', '2122380851', None, 5060, 0, frozendict({}), frozendict({})), 'Tony Nelson', frozendict({})), 'CSeq': (1, 'CANCEL'), 'Call-ID': FrozenHeader('Call-ID', '15910a01b2113c693de1be43ea86b36b5d02db7@64.190.127.4'), 'Max-Forwards': 70}, state='disconnected', prev_state='early', method='CANCEL', request_uri=FrozenSIPURI('192.168.38.68', 'xwdmnbic', None, 12693, 0, frozendict({'maddr': '64.190.10.2'}), frozendict({})))
2010-09-14 10:23:09.849744: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x18c53290> data=TimestampedNotificationData(service='stun', timestamp=datetime.datetime(2010, 9, 14, 10, 23, 9, 843947), error=NXDOMAIN(), uri=SIPURI('starpoint.com', None, None, None, False, {}, {}), query_name='_stun._udp.starpoint.com', context='lookup_service', query_type='SRV', answer=None)
2010-09-14 10:23:09.849898: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x18c53290> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 23, 9, 844559), error='No stun servers found for domain starpoint.com')
2010-09-14 10:23:25.032453: Notification name=DNSLookupTrace sender=<sipsimple.lookup.DNSLookup object at 0x18c53290> data=TimestampedNotificationData(service='stun', timestamp=datetime.datetime(2010, 9, 14, 10, 23, 25, 31919), error=Timeout(), uri=SIPURI('sip2sip.info', None, None, None, False, {}, {}), query_name='_stun._udp.sip2sip.info', context='lookup_service', query_type='SRV', answer=None)
2010-09-14 10:23:25.033989: Notification name=DNSLookupDidFail sender=<sipsimple.lookup.DNSLookup object at 0x18c53290> data=TimestampedNotificationData(timestamp=datetime.datetime(2010, 9, 14, 10, 23, 25, 33084), error='Timeout in lookup for stun servers for domain sip2sip.info')