Skip to content

Instantly share code, notes, and snippets.

@azmeuk

azmeuk/aioxmpp.log

Created January 2, 2017 16:39
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save azmeuk/767bfcdf7fce217bd7af18f88d99003d to your computer and use it in GitHub Desktop.
Save azmeuk/767bfcdf7fce217bd7af18f88d99003d to your computer and use it in GitHub Desktop.
Download ZIP
Firebase Cloud Messaging and aioxmpp
Raw
aioxmpp.log
2017-01-02 17:37:46,605 selector_events:53 DEBUG Using selector: EpollSelector
2017-01-02 17:37:46,606 callbacks:478 DEBUG connecting <bound method PresenceManagedClient._handle_stream_established of <aioxmpp.node.PresenceManagedClient object at 0x7f34ea043d30>> with mode <bound method AdHocSignal.STRONG of <class 'aioxmpp.callbacks.AdHocSignal'>>
2017-01-02 17:37:46,607 callbacks:478 DEBUG connecting <Future pending> with mode <bound method AdHocSignal.AUTO_FUTURE of <class 'aioxmpp.callbacks.AdHocSignal'>>
2017-01-02 17:37:46,607 callbacks:478 DEBUG connecting <Future pending> with mode <bound method AdHocSignal.AUTO_FUTURE of <class 'aioxmpp.callbacks.AdHocSignal'>>
2017-01-02 17:37:46,607 callbacks:478 DEBUG connecting <bound method AbstractClient._stream_failure of <aioxmpp.node.PresenceManagedClient object at 0x7f34ea043d30>> with mode <bound method AdHocSignal.STRONG of <class 'aioxmpp.callbacks.AdHocSignal'>>
2017-01-02 17:37:46,607 callbacks:478 DEBUG connecting <bound method AbstractClient._stream_destroyed of <aioxmpp.node.PresenceManagedClient object at 0x7f34ea043d30>> with mode <bound method AdHocSignal.STRONG of <class 'aioxmpp.callbacks.AdHocSignal'>>
2017-01-02 17:37:46,608 node:199 DEBUG domain gcm.googleapis.com: trying to connect to 'fcm-xmpp.googleapis.com':5235 using <aioxmpp.connector.XMPPOverTLSConnector object at 0x7f34ecf1b3c8>
2017-01-02 17:37:46,632 __init__:289 DEBUG _initiate_tls called
2017-01-02 17:37:46,632 __init__:314 DEBUG _tls_do_handshake called
2017-01-02 17:37:46,632 __init__:322 DEBUG registering reader for _tls_do_handshake
2017-01-02 17:37:46,651 __init__:314 DEBUG _tls_do_handshake called
2017-01-02 17:37:46,651 __init__:322 DEBUG registering reader for _tls_do_handshake
2017-01-02 17:37:46,652 __init__:314 DEBUG _tls_do_handshake called
2017-01-02 17:37:46,652 security_layer:292 INFO verifying certificate (preverify=1)
2017-01-02 17:37:46,652 security_layer:292 INFO verifying certificate (preverify=1)
2017-01-02 17:37:46,653 security_layer:292 INFO verifying certificate (preverify=1)
2017-01-02 17:37:46,654 __init__:322 DEBUG registering reader for _tls_do_handshake
2017-01-02 17:37:46,672 __init__:314 DEBUG _tls_do_handshake called
2017-01-02 17:37:46,672 __init__:256 DEBUG clearing readers/writers
2017-01-02 17:37:46,673 __init__:346 DEBUG handshake complete
2017-01-02 17:37:46,673 __init__:352 DEBUG post handshake scheduled via callback
2017-01-02 17:37:46,673 __init__:370 DEBUG _tls_post_handshake called
2017-01-02 17:37:46,674 protocol:158 DEBUG SENT b'<?xml version="1.0"?><stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="gcm.googleapis.com" version="1.0">'
2017-01-02 17:37:46,674 __init__:497 DEBUG _write_ready: nothing more to write, removing writer
2017-01-02 17:37:46,839 protocol:476 DEBUG RECV b'<stream:stream from="gcm.googleapis.com" id="8D5E507997367EA0" version="1.0" xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client">'
2017-01-02 17:37:46,840 protocol:476 DEBUG RECV b'<stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>X-OAUTH2</mechanism><mechanism>X-GOOGLE-TOKEN</mechanism><mechanism>PLAIN</mechanism></mechanisms></stream:features>'
2017-01-02 17:37:46,840 node:220 DEBUG domain gcm.googleapis.com: connection succeeded using <aioxmpp.connector.XMPPOverTLSConnector object at 0x7f34ecf1b3c8>
2017-01-02 17:37:46,841 __init__:482 INFO attempting PLAIN mechanism
2017-01-02 17:37:46,843 protocol:158 DEBUG SENT b'<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">xxxxxx=</auth>'
2017-01-02 17:37:46,843 __init__:497 DEBUG _write_ready: nothing more to write, removing writer
2017-01-02 17:37:46,916 protocol:476 DEBUG RECV b'<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>'
2017-01-02 17:37:46,917 protocol:158 DEBUG SENT b''
2017-01-02 17:37:46,918 protocol:158 DEBUG SENT b'<?xml version="1.0"?><stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="gcm.googleapis.com" version="1.0">'
2017-01-02 17:37:46,919 __init__:497 DEBUG _write_ready: nothing more to write, removing writer
2017-01-02 17:37:47,005 protocol:476 DEBUG RECV b'<stream:stream from="gcm.googleapis.com" id="D719A232896D5959" version="1.0" xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client">'
2017-01-02 17:37:47,007 protocol:476 DEBUG RECV b'<stream:features><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features>'
2017-01-02 17:37:47,008 node:634 DEBUG negotiating stream (server_can_do_sm=False)
2017-01-02 17:37:47,009 callbacks:478 DEBUG connecting <bound method StanzaStream._xmlstream_failed of <aioxmpp.stream.StanzaStream object at 0x7f34ea057160>> with mode <bound method AdHocSignal.STRONG of <class 'aioxmpp.callbacks.AdHocSignal'>>
2017-01-02 17:37:47,009 stream:1543 DEBUG broker task started as <Task pending coro=<StanzaStream._run() running at /home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py:1630> cb=[StanzaStream._done_handler()]>
2017-01-02 17:37:47,010 node:648 DEBUG binding to resource
2017-01-02 17:37:47,011 stream:1187 DEBUG iq response future registered: from=None, id='x9a5oYLgiHWZtqeq7wJnl'
2017-01-02 17:37:47,011 stream:2141 DEBUG sending <iq from=None to=None id='x9a5oYLgiHWZtqeq7wJnl' type=<IQType.SET: 'set'> data=<aioxmpp.rfc6120.Bind object at 0x7f34e8dcb550>> and waiting for it to be sent
2017-01-02 17:37:47,012 stream:1724 DEBUG enqueued stanza <iq from=None to=None id='x9a5oYLgiHWZtqeq7wJnl' type=<IQType.SET: 'set'> data=<aioxmpp.rfc6120.Bind object at 0x7f34e8dcb550>> with token <StanzaToken id=0x00007f34e8dcb860>
2017-01-02 17:37:47,012 stream:2161 DEBUG using token <StanzaToken id=0x00007f34e8dcb860>
2017-01-02 17:37:47,014 stream:1016 DEBUG forwarding stanza to xmlstream: <iq from=None to=None id='x9a5oYLgiHWZtqeq7wJnl' type=<IQType.SET: 'set'> data=<aioxmpp.rfc6120.Bind object at 0x7f34e8dcb550>>
2017-01-02 17:37:47,015 protocol:158 DEBUG SENT b'<iq type="set" id="x9a5oYLgiHWZtqeq7wJnl"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/></iq>'
2017-01-02 17:37:47,015 stream:2144 DEBUG token <StanzaToken id=0x00007f34e8dcb860> enters state <StanzaState.SENT_WITHOUT_SM: 3>
2017-01-02 17:37:47,016 __init__:497 DEBUG _write_ready: nothing more to write, removing writer
2017-01-02 17:37:47,067 protocol:476 DEBUG RECV b'<iq id="x9a5oYLgiHWZtqeq7wJnl" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>xxxx@gcm.googleapis.com/2016D8D5</jid></bind></iq>'
2017-01-02 17:37:47,070 protocol:476 DEBUG RECV b' '
2017-01-02 17:37:47,071 stream:748 DEBUG incoming iq: <iq from=None to=None id='x9a5oYLgiHWZtqeq7wJnl' type=<IQType.RESULT: 'result'> data=<aioxmpp.rfc6120.Bind object at 0x7f34e8dcbbe0>>
2017-01-02 17:37:47,071 stream:751 DEBUG iq is response
2017-01-02 17:37:47,072 stream:757 DEBUG iq response delivered to key (None, 'x9a5oYLgiHWZtqeq7wJnl')
2017-01-02 17:37:47,073 node:686 INFO bound to jid: 175344936614@gcm.googleapis.com/2016D8D5
2017-01-02 17:37:47,073 node:612 DEBUG remote server announces support for legacy sessions
2017-01-02 17:37:47,074 stream:1187 DEBUG iq response future registered: from=None, id='xsBwBDejAXDRIhMCM32Eb'
2017-01-02 17:37:47,074 stream:2141 DEBUG sending <iq from=None to=None id='xsBwBDejAXDRIhMCM32Eb' type=<IQType.SET: 'set'> data=<aioxmpp.rfc3921.Session object at 0x7f34e8dcb9e8>> and waiting for it to be sent
2017-01-02 17:37:47,075 stream:1724 DEBUG enqueued stanza <iq from=None to=None id='xsBwBDejAXDRIhMCM32Eb' type=<IQType.SET: 'set'> data=<aioxmpp.rfc3921.Session object at 0x7f34e8dcb9e8>> with token <StanzaToken id=0x00007f34e8dcba58>
2017-01-02 17:37:47,075 stream:2161 DEBUG using token <StanzaToken id=0x00007f34e8dcba58>
2017-01-02 17:37:47,076 stream:1016 DEBUG forwarding stanza to xmlstream: <iq from=None to=None id='xsBwBDejAXDRIhMCM32Eb' type=<IQType.SET: 'set'> data=<aioxmpp.rfc3921.Session object at 0x7f34e8dcb9e8>>
2017-01-02 17:37:47,077 protocol:158 DEBUG SENT b'<iq type="set" id="xsBwBDejAXDRIhMCM32Eb"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>'
2017-01-02 17:37:47,077 stream:2144 DEBUG token <StanzaToken id=0x00007f34e8dcba58> enters state <StanzaState.SENT_WITHOUT_SM: 3>
2017-01-02 17:37:47,078 __init__:497 DEBUG _write_ready: nothing more to write, removing writer
2017-01-02 17:37:47,129 protocol:476 DEBUG RECV b'<iq type="result" id="xsBwBDejAXDRIhMCM32Eb"/>'
2017-01-02 17:37:47,130 stream:748 DEBUG incoming iq: <iq from=None to=None id='xsBwBDejAXDRIhMCM32Eb' type=<IQType.RESULT: 'result'>>
2017-01-02 17:37:47,130 stream:751 DEBUG iq is response
2017-01-02 17:37:47,130 stream:757 DEBUG iq response delivered to key (None, 'xsBwBDejAXDRIhMCM32Eb')
2017-01-02 17:37:47,130 node:619 DEBUG legacy session negotiated (upgrade your server!)
2017-01-02 17:37:47,131 stream:1724 DEBUG enqueued stanza <presence from=None to=None id='xpy73G6WnKmaMwfvvm4B3' type=<PresenceType.AVAILABLE: None>> with token <StanzaToken id=0x00007f34e8dcba90>
2017-01-02 17:37:47,131 stream:2141 DEBUG sending <message from=None to=None id=None type=<MessageType.NORMAL: 'normal'>> and waiting for it to be sent
2017-01-02 17:37:47,131 stream:1724 DEBUG enqueued stanza <message from=None to=None id='xEXZsNbDbdKlfqB2aIOM8' type=<MessageType.NORMAL: 'normal'>> with token <StanzaToken id=0x00007f34e8dcb4a8>
2017-01-02 17:37:47,131 stream:2161 DEBUG using token <StanzaToken id=0x00007f34e8dcb4a8>
2017-01-02 17:37:47,132 stream:1016 DEBUG forwarding stanza to xmlstream: <presence from=None to=None id='xpy73G6WnKmaMwfvvm4B3' type=<PresenceType.AVAILABLE: None>>
2017-01-02 17:37:47,132 protocol:158 DEBUG SENT b'<presence id="xpy73G6WnKmaMwfvvm4B3"/>'
2017-01-02 17:37:47,132 stream:1016 DEBUG forwarding stanza to xmlstream: <message from=None to=None id='xEXZsNbDbdKlfqB2aIOM8' type=<MessageType.NORMAL: 'normal'>>
2017-01-02 17:37:47,132 protocol:158 DEBUG SENT b'<message id="xEXZsNbDbdKlfqB2aIOM8"/>'
2017-01-02 17:37:47,133 stream:2144 DEBUG token <StanzaToken id=0x00007f34e8dcb4a8> enters state <StanzaState.SENT_WITHOUT_SM: 3>
2017-01-02 17:37:47,133 __init__:497 DEBUG _write_ready: nothing more to write, removing writer
2017-01-02 17:37:47,184 protocol:476 DEBUG RECV b'<message id="xEXZsNbDbdKlfqB2aIOM8" type="error" to="175344936614@gcm.googleapis.com/2016D8D5"><error code="400" type="modify"><bad-request xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/><text xmlns="urn:ietf:params:xml:ns:xmpp-stanzas">InvalidJson : MissingPayload</text></error></message>'
2017-01-02 17:37:47,185 stream:796 DEBUG incoming messgage: <message from=None to='175344936614@gcm.googleapis.com/2016D8D5' id='xEXZsNbDbdKlfqB2aIOM8' type=<MessageType.ERROR: 'error'>>
2017-01-02 17:37:47,185 stream:1673 DEBUG task terminating, rescuing stanzas and clearing handlers
2017-01-02 17:37:47,186 stream:704 DEBUG destroying stream state
2017-01-02 17:37:47,186 protocol:158 DEBUG SENT b'</stream:stream>'
2017-01-02 17:37:47,186 stream:693 ERROR broker task failed
Traceback (most recent call last):
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 680, in _done_handler
task.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 274, in result
raise self._exception
File "/usr/lib64/python3.5/asyncio/tasks.py", line 239, in _step
result = coro.send(None)
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 1661, in _run
incoming_fut.result())
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 957, in _process_incoming
self._process_incoming_message(stanza_obj)
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 811, in _process_incoming_message
(stanza_obj.type_, stanza_obj.from_.bare()),
AttributeError: 'NoneType' object has no attribute 'bare'
2017-01-02 17:37:47,187 node:720 ERROR stream failed: 'NoneType' object has no attribute 'bare'
2017-01-02 17:37:47,187 node:728 INFO stopping stream
2017-01-02 17:37:47,187 __init__:497 DEBUG _write_ready: nothing more to write, removing writer
2017-01-02 17:37:47,187 node:596 ERROR main failed
Traceback (most recent call last):
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/node.py", line 591, in _on_main_done
task.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 274, in result
raise self._exception
File "/usr/lib64/python3.5/asyncio/tasks.py", line 239, in _step
result = coro.send(None)
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/node.py", line 744, in _main
yield from self._main_impl()
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/node.py", line 721, in _main_impl
raise exc
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 680, in _done_handler
task.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 274, in result
raise self._exception
File "/usr/lib64/python3.5/asyncio/tasks.py", line 239, in _step
result = coro.send(None)
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 1661, in _run
incoming_fut.result())
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 957, in _process_incoming
self._process_incoming_message(stanza_obj)
File "/home/eloi/dev/push-server/local.virtualenv/lib/python3.5/site-packages/aioxmpp/stream.py", line 811, in _process_incoming_message
(stanza_obj.type_, stanza_obj.from_.bare()),
AttributeError: 'NoneType' object has no attribute 'bare'
2017-01-02 17:37:47,188 protocol:353 DEBUG waiting for at most 15 seconds for peer stream footer
2017-01-02 17:37:47,189 protocol:476 DEBUG RECV b'</stream:stream>'
2017-01-02 17:37:47,190 __init__:389 DEBUG _tls_do_shutdown called
2017-01-02 17:37:47,190 __init__:256 DEBUG clearing readers/writers
2017-01-02 17:37:47,190 __init__:256 DEBUG clearing readers/writers
2017-01-02 17:37:47,190 __init__:239 DEBUG _force_close called
2017-01-02 17:37:47,190 __init__:256 DEBUG clearing readers/writers
Raw
aioxmpp.py
import asyncio, logging, aioxmpp.xso, aioxmpp.utils, aioxmpp.node, aioxmpp.security_layer, aioxmpp.structs, aioxmpp.stanza, colorlog, signal, sys, uuid, json
FCM_SERVER_URL = "fcm-xmpp.googleapis.com"
FCM_SERVER_PORT = 5235
RECIPIENT = "xxx"
FCM_API_KEY = 'xxxx'
FCM_APP_ID = 'x'
FCM_JID = "%s@gcm.googleapis.com" % FCM_APP_ID
class ProtoClass:
client = None
def make_sigint_event(self):
event = asyncio.Event()
loop = asyncio.get_event_loop()
loop.add_signal_handler(signal.SIGINT, event.set)
return event
@asyncio.coroutine
def do_things(self):
stop_event = self.make_sigint_event()
msg = aioxmpp.stanza.Message(type_="normal")
yield from self.client.stream.send_and_wait_for_sent(msg)
yield from stop_event.wait()
@asyncio.coroutine
def main(self):
self.client = aioxmpp.node.PresenceManagedClient(
aioxmpp.JID.fromstr(FCM_JID),
aioxmpp.make_security_layer(FCM_API_KEY),
override_peer = [(FCM_SERVER_URL, FCM_SERVER_PORT, aioxmpp.connector.XMPPOverTLSConnector())],
)
cm = self.client.connected()
yield from cm.__aenter__()
try:
yield from self.do_things()
except:
if not (yield from cm.__aexit__(*sys.exc_info())):
raise
else:
yield from cm.__aexit__(None, None, None)
if __name__ == "__main__":
proto = ProtoClass()
aioloop = asyncio.get_event_loop()
try:
aioloop.run_until_complete(proto.main())
finally:
aioloop.close()
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment