jlguardi / yowsup

The python WhatsApp library
http://www.openwhatsapp.org
GNU General Public License v3.0
42 stars 23 forks source link

[INVESTIGATE] Corrupt xml #17

Open jlguardi opened 8 years ago

jlguardi commented 8 years ago

Reported by @cfenollosa en #7


DEBUG:yowsup.layers.logger.layer:rx:
<message partµÌlþ2ç{·úÓñ/ØÇ!÷eä90@s.whatsapp.net" t="1459261226" from="34639057486-1300625051@g.us" offline="0" type="text" id="6B2351756D2878E034" notify="Aupa Erreala!">
*ÑçäAtiHä~j×>" type="pkmsg" v="2d¬2?fß?Ä){2zXh7
"³3
!áWæÇUßZc篼§MùeãHØåô< í ^Kx"ýФÜs7øxñn

Probably due to crypto(auth) or coder layer.

freelo commented 8 years ago

This output is very strange indeed, which makes me assume that it is not a real error. Printing encrypted/binary data may produce unexpected results, because it may contain control characters that are written to the console. Since it actually is taken from a console (see #7), I would not consider this xml corrupt (unless one can prove that it happens when dumping to a file -- which is quite unlikely IMHO).

jlguardi commented 8 years ago

@freelo You are right. Please, @cfenollosa could you log to file and post results? To do this, add:

logger.basicConfig(filename='yowsup.log')
teehamaral commented 8 years ago

@jlguardi the problem has not been solved completely, unfortunately (#7). Initially the messages were received without delay, after some time running, the messages stopped coming and there are times that none is received. I am using the version of the master branch of the `jlguardi / yowsup / 'repository.

Logs after appearing the warning "axolotl.sessionbuilder: We've already set up the session for this V3 message, letting fall through bundled message ...":

DEBUG:yowsup.stacks.yowstack:Initializing stack
DEBUG:yowsup.stacks.yowstack:Constructed Network Layer
DEBUG:yowsup.stacks.yowstack:Constructed Stanza Regulator Layer
DEBUG:yowsup.stacks.yowstack:Constructed Crypt Layer
DEBUG:yowsup.stacks.yowstack:Constructed Coder Layer
DEBUG:yowsup.stacks.yowstack:Constructed Logger Layer
DEBUG:yowsup.stacks.yowstack:Constructed Axolotl Layer
DEBUG:yowsup.stacks.yowstack:Constructed Authentication Layer - Messages Layer - Receipt Layer - Ack Layer - Presence Layer - Ib Layer - Iq Layer - notification Ib Layer - Iq Layer - Chatstate Layer - call Layer - Groups Iq Layer - Media Layer - Privacy Layer - Profiles Layer
DEBUG:yowsup.stacks.yowstack:Constructed Interface Layer
DEBUG:yowsup.layers.network.layer:Connecting to e4.whatsapp.net:443
DEBUG:yowsup.layers.logger.layer:tx:
<stream:features>
</stream:features>

DEBUG:yowsup.layers.logger.layer:tx:
<auth passive="false" user="558281160309" mechanism="WAUTH-2">
񪳽�[.��g��Ϡm�:�Є�ʪ7�t�61UqTc��(�!q��Hz���
HEX:d0787b327c5c599d743053d8b7d1b3475ae31c065c3db174d0363155715463a7be0e28f32171ead90e487adeedf28c0df1aab3bd8a5b2e8bff67c4cccfa06d13d73af18d1b8818d084cccaaa3718
</auth>

DEBUG:yowsup.layers.logger.layer:rx:
<stream:features>
</stream:features>

DEBUG:yowsup.layers.logger.layer:rx:
<success status="active" kind="free" creation="1452721835" expiration="4444444444" props="4" t="1459371758">
p��Qr���dVm
Q�F�o
HEX:70dfc01951728b89ec64566d0a5110ff0146f26f
</success>

DEBUG:yowsup.layers.protocol_iq.layer:starting ping thread.
DEBUG:yowsup.layers.logger.layer:rx:
<ib from="s.whatsapp.net">
<dirty timestamp="1459371758" type="groups">
</dirty>
</ib>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt type="read" offline="3" from="558299227801@s.whatsapp.net" id="1459342987A12" t="1459342986">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" type="read" id="1459342987A12" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt offline="3" from="558299227801@s.whatsapp.net" id="1459342987A12" t="1459342986">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" id="1459342987A12" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt type="read" offline="3" from="558299227801@s.whatsapp.net" id="1459342987A12" t="1459342986">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" type="read" id="1459342987A12" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt type="read" offline="3" from="558299489287@s.whatsapp.net" id="1459342989A13" t="1459342987">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299489287@s.whatsapp.net" type="read" id="1459342989A13" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt type="read" offline="3" from="558299227801@s.whatsapp.net" id="1459342990A14" t="1459342988">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" type="read" id="1459342990A14" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt offline="3" from="558299227801@s.whatsapp.net" id="1459342990A14" t="1459342988">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" id="1459342990A14" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt type="read" offline="3" from="558299227801@s.whatsapp.net" id="1459342990A14" t="1459342988">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" type="read" id="1459342990A14" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt type="read" offline="3" from="558299227801@s.whatsapp.net" id="1459342992A15" t="1459342990">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" type="read" id="1459342992A15" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt offline="3" from="558299227801@s.whatsapp.net" id="1459342992A15" t="1459342990">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" id="1459342992A15" class="receipt">
</ack>

DEBUG:yowsup.layers.logger.layer:rx:
<receipt type="read" offline="3" from="558299227801@s.whatsapp.net" id="1459342992A15" t="1459342990">
</receipt>

DEBUG:yowsup.layers.logger.layer:tx:
<ack to="558299227801@s.whatsapp.net" type="read" id="1459342992A15" class="receipt">
</ack>

DEBUG:yowsup.layers.protocol_iq.layer:ping queue size: 1
DEBUG:yowsup.layers.logger.layer:tx:
<iq xmlns="w:p" type="get" id="1">
</iq>

DEBUG:yowsup.layers.logger.layer:rx:
<iq type="result" from="558281160309@s.whatsapp.net" id="1" t="1459371809">
</iq>

DEBUG:yowsup.layers.protocol_iq.layer:ping queue size: 1
DEBUG:yowsup.layers.logger.layer:tx:
<iq xmlns="w:p" type="get" id="2">
</iq>

DEBUG:yowsup.layers.logger.layer:rx:
<iq type="result" from="558281160309@s.whatsapp.net" id="2" t="1459371859">
</iq>

DEBUG:yowsup.layers.protocol_iq.layer:ping queue size: 1
DEBUG:yowsup.layers.logger.layer:tx:
<iq xmlns="w:p" type="get" id="3">
</iq>

DEBUG:yowsup.layers.logger.layer:rx:
<iq type="result" from="558281160309@s.whatsapp.net" id="3" t="1459371909">
</iq>

DEBUG:yowsup.layers.protocol_iq.layer:ping queue size: 1
DEBUG:yowsup.layers.logger.layer:tx:
<iq xmlns="w:p" type="get" id="4">
</iq>

DEBUG:yowsup.layers.logger.layer:rx:
<iq type="result" from="558281160309@s.whatsapp.net" id="4" t="1459371959">
</iq>

DEBUG:yowsup.layers.protocol_iq.layer:ping queue size: 1
DEBUG:yowsup.layers.logger.layer:tx:
<iq xmlns="w:p" type="get" id="5">
</iq>

DEBUG:yowsup.layers.logger.layer:rx:
<iq type="result" from="558281160309@s.whatsapp.net" id="5" t="1459372009">
</iq>

DEBUG:yowsup.layers.protocol_iq.layer:ping queue size: 1
DEBUG:yowsup.layers.logger.layer:tx:
<iq xmlns="w:p" type="get" id="6">
</iq>

DEBUG:yowsup.layers.logger.layer:rx:
<iq type="result" from="558281160309@s.whatsapp.net" id="6" t="1459372059">
</iq>

DEBUG:yowsup.layers.logger.layer:rx:
<stream:error>
<ack id="1459342987-12">
</ack>
</stream:error>
cfenollosa commented 8 years ago

I've added

import logging
logging.basicConfig(filename='/tmp/yowsup.log')

to yowsup/demos/cli/stack.py (and reinstalled the package), but it's not writing the log file for some reason. Any ideas?

relima commented 8 years ago

@jlguardi I am willing to provide you with my number`s password. Would that help?

jlguardi commented 8 years ago

@relima I could try your credentials (send me a mail to mylogin at gmail dot com) However try before master due to I've fixed a bug in coder 1 hour ago.

relima commented 8 years ago

@jlguardi - Sent! Unfortunately, the bug still persists with the latest version on master.

jlguardi commented 8 years ago

I guess that latest coder fix all this issues. Try it and report if persists.

jlguardi commented 8 years ago

@Marcovus could you please post here logs?

Marcovus commented 8 years ago

Yes, give me one day.

Marcovus commented 8 years ago

hello, i have it here - i removed the ping logs in the middle:

` 2016-04-12 21:26:18,079 DEBUG Main Plugin: whatsapp -- plugin.py:init:43 2016-04-12 21:26:23,034 DEBUG Main Initializing stack -- yowstack.py:_construct:198 2016-04-12 21:26:23,038 DEBUG Main Constructed Network Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,041 DEBUG Main Constructed Stanza Regulator Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,043 DEBUG Main Constructed Crypt Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,045 DEBUG Main Constructed Coder Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,047 DEBUG Main Constructed Logger Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,050 DEBUG Main Constructed Axolotl Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,052 DEBUG Main Constructed Authentication Layer - Messages Layer - Receipt Layer - Ack Layer - Ib Layer - Iq Layer - Media Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,056 DEBUG Main Constructed Interface Layer -- yowstack.py:_construct:214 2016-04-12 21:26:23,057 INFO Main WhatsApp-Plugin : EVENT org.openwhatsapp.yowsup.event.network.connect -- SmarthomeLayer.py:onEvent:116 2016-04-12 21:26:23,061 DEBUG Main Connecting to e1.whatsapp.net:443 -- layer.py:createConnection:58 2016-04-12 21:26:55,973 DEBUG whatsapp tx: stream:features

/stream:features -- layer.py:send:8 2016-04-12 21:26:56,092 DEBUG whatsapp tx:

# XXXX [ãùã0øËÍ=ã»ç1¼G–GƌË|ÀÚÃý×QdÛ86f1928ea5debee5fda59ab120802'

-- layer.py:send:8 2016-04-12 21:27:56,905 INFO whatsapp WhatsApp-Plugin : EVENT org.openwhatsapp.yowsup.event.network.connected -- SmarthomeLayer.py:onEvent:116 2016-04-12 21:27:56,907 INFO whatsapp WhatsApp-Plugin : Connected -- SmarthomeLayer.py:onEvent:140 2016-04-12 21:27:57,073 DEBUG whatsapp rx: stream:features /stream:features -- layer.py:receive:13 2016-04-12 21:27:57,080 DEBUG whatsapp rx:

à*+WÜ >sbEþù°’òšNc HEX3:b'8fe01a2a2b57dca03e736245fef9b092f29a4e63'

-- layer.py:receive:13 2016-04-12 21:27:57,087 DEBUG whatsapp starting ping thread. -- layer.py:onAuthed:64 2016-04-12 21:27:57,091 DEBUG whatsapp test -- SmarthomeLayer.py:onSuccess:79 2016-04-12 21:27:57,096 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:27:57,100 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:28:47,176 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:28:47,179 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:28:47,298 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:28:47,302 DEBUG whatsapp Received IQ: ID: 1 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92

2016-04-12 21:29:37,278 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:29:37,283 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:29:37,404 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:29:37,410 DEBUG whatsapp Received IQ: ID: 2 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 21:30:27,370 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:30:27,374 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:30:27,493 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:30:27,498 DEBUG whatsapp Received IQ: ID: 3 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 21:31:17,501 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:31:17,504 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:31:17,618 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:31:17,620 DEBUG whatsapp Received IQ: ID: 4 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92

2016-04-12 21:32:07,857 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:32:07,859 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:32:07,868 DEBUG env_stat Item env.core.threads = 13 via Logic None None -- item.py:__update:373 2016-04-12 21:32:07,937 WARNING fb-cycle Problem fetching https://192.168.10.1:49443/upnp/control/hosts: 500 Internal Server Error -- www.py:fetch_url:109 2016-04-12 21:32:07,982 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:32:07,984 DEBUG whatsapp Received IQ: ID: 5 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92

2016-04-12 21:32:57,954 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:32:57,957 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:32:58,087 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:32:58,089 DEBUG whatsapp Received IQ: ID: 6 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92016-04-12 21:34:38,145 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:34:38,148 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:34:38,268 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:34:38,272 DEBUG whatsapp Received IQ: ID: 8 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92

2016-04-12 21:35:28,353 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:35:28,357 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:35:28,477 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:35:28,482 DEBUG whatsapp Received IQ: ID: 9 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 21:36:18,448 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:36:18,452 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:36:18,572 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:36:18,582 DEBUG whatsapp Received IQ: ID: 10 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 21:37:08,546 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:37:08,547 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:37:08,658 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:37:08,660 DEBUG whatsapp Received IQ: ID: 11 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 21:37:58,633 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:37:58,637 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:37:58,758 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:37:58,760 DEBUG whatsapp Received IQ: ID: 12 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 21:38:48,736 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:38:48,739 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:38:48,768 DEBUG Scheduler strom_rest_momentanverbrauch next time: 2016-04-12 21:38:58+02:00 -- scheduler.py:_next_time:303 2016-04-12 21:38:48,859 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:38:48,864 DEBUG whatsapp Received IQ: ID: 13 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 21:39:38,856 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:39:38,860 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:39:38,980 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 21:39:38,985 DEBUG whatsapp Received IQ: ID: 14 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92

2016-04-12 21:40:28,953 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 21:40:28,956 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 21:40:29,075 DEBUG whatsapp rx:

-- layer.py:receive:13

2016-04-12 22:56:29,056 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 22:56:29,059 DEBUG YowPingThread-7 tx:

-- layer.py:send:8 2016-04-12 22:56:29,179 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 22:56:29,184 DEBUG whatsapp Received IQ: ID: 106 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 22:57:19,317 DEBUG YowPingThread-7 ping queue size: 1 -- layer.py:waitPong:54 2016-04-12 22:57:19,318 DEBUG YowPingThread-7 tx:

-- layer.py:send:8

2016-04-12 22:57:19,433 DEBUG whatsapp rx:

-- layer.py:receive:13 2016-04-12 22:57:19,443 DEBUG whatsapp Received IQ: ID: 107 Type: result XMLNS: None To: None From: MYNUMBER@s.whatsapp.net -- SmarthomeLayer.py:onIq:92 2016-04-12 22:57:19,530 DEBUG whatsapp rx: stream:error

/stream:error -- layer.py:receive:13 2016-04-12 22:57:19,532 INFO whatsapp Auth Error, reason Unhandled stream:error node: stream:error

/stream:error -- init.py:run:99`

thanks in advance