Author

Topic: the bs "Satoshi:0.8.99" and 0 byte pings (Read 1341 times)

member
Activity: 106
Merit: 10
November 06, 2013, 03:28:36 AM
#7
Hmm, with your commit 0.9 users will have no visible way of seeing these protocol breaking bad nodes.  Perhaps a -debug mode only warning would be helpful?

Aye, you're right.  I have that in already, but only for pong.  Don't have it for ping.  Should be easy enough to add.

Josh
newbie
Activity: 32
Merit: 0
November 05, 2013, 04:27:06 PM
#6
The thing is, I don't want to firewall these nodes as I receive blocks from some of them.

Inv-sending nodes aren't exactly a rarity, so I don't understand your concern.

Frankly, nodes are far too lenient with the messages they respond to or accept.

That includes 0-byte pings and spam.
zvs
legendary
Activity: 1680
Merit: 1000
https://web.archive.org/web/*/nogleg.com
November 04, 2013, 08:27:22 AM
#5
I don't see this behavior with a second node that has 50 connections (& same client version as other server), runs p2pool, & has listen=0 ...  also doesn't appear on my local node that has a single bitcoind connection & runs p2pool

I am thinking you won't see this message unless these odd peers are connected to you *and* you're running p2pool?

I know it'd be caused by (ed: whatever interaction is occuring with):

p2p.py:        self.pinger.start(30)

sr. member
Activity: 263
Merit: 250
November 04, 2013, 05:55:57 AM
#4
Strange!

I worked on a recent patch for Bitcoin that added ping time measurement (using ping/pong).  During development, I ran into some strange nodes out there that were doing something similar.

https://github.com/bitcoin/bitcoin/pull/2937#issuecomment-23457819

Here's the referenced IRC chat:

http://bitcoinstats.com/irc/bitcoin-dev/logs/2013/08/28#l1377673880

Many of these IP addresses match!!

Only thing is, this was for the *pong* message, not ping.  They were sending me pong messages of zero size.  I now check the size before doing any processing, and just throw it out if it's too small, to avoid the spam messages you get about the exception.  I don't remember ever getting any undersized *ping* messages from them.

I remember the version also, it was 0.8.99.  I think this just means you're running the latest Bitcoin from GitHub, compiled yourself, and thus not an official release?  Not sure about that, though.

Didn't think this had anything to do with p2pool, though.  Interesting.

Josh


p2pool only connects to a local node and pretends to be another client to getblocks.  None of these bad peers are p2pool itself.

Hmm, with your commit 0.9 users will have no visible way of seeing these protocol breaking bad nodes.  Perhaps a -debug mode only warning would be helpful?
member
Activity: 106
Merit: 10
November 04, 2013, 04:17:01 AM
#3
Strange!

I worked on a recent patch for Bitcoin that added ping time measurement (using ping/pong).  During development, I ran into some strange nodes out there that were doing something similar.

https://github.com/bitcoin/bitcoin/pull/2937#issuecomment-23457819

Here's the referenced IRC chat:

http://bitcoinstats.com/irc/bitcoin-dev/logs/2013/08/28#l1377673880

Many of these IP addresses match!!

Only thing is, this was for the *pong* message, not ping.  They were sending me pong messages of zero size.  I now check the size before doing any processing, and just throw it out if it's too small, to avoid the spam messages you get about the exception.  I don't remember ever getting any undersized *ping* messages from them.

I remember the version also, it was 0.8.99.  I think this just means you're running the latest Bitcoin from GitHub, compiled yourself, and thus not an official release?  Not sure about that, though.

Didn't think this had anything to do with p2pool, though.  Interesting.

Josh
sr. member
Activity: 263
Merit: 250
November 04, 2013, 03:17:29 AM
#2
https://github.com/forrestv/p2pool/issues/137
Apparently we know one way the zero byte pings can happen.  It happened by accident with a recent p2pool change.  In this 0.8.99 instance however it may not be an accident...
zvs
legendary
Activity: 1680
Merit: 1000
https://web.archive.org/web/*/nogleg.com
November 03, 2013, 10:01:35 AM
#1
Code:
2013-11-03 05:09:44 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:10:14 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:10:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:11:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:11:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:12:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:12:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:13:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:13:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:14:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:14:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:15:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:15:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:16:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:16:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:17:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:17:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:18:02 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length



2013-11-03 11:33:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:34:03 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:34:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:35:03 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:35:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:36:03 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:36:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:37:03 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:37:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:38:03 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:38:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:39:03 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:39:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:40:03 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:40:33 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:41:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:41:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:42:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:42:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:43:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:43:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:44:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:44:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:45:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:45:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:46:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:46:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:47:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:47:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:48:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:48:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:49:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:49:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:50:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:50:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:51:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:51:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:52:04 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 11:52:34 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length

They also all have:

ProcessMessage(ping, 0 bytes) FAILED immediately following that message.

This is where it started:

Code:
2013-11-03 05:11:27 accepted connection 176.9.144.41:32687
2013-11-03 05:11:27 accepted connection 46.4.64.21:56061
2013-11-03 05:11:27 accepted connection 5.9.30.207:42607
2013-11-03 05:11:27 accepted connection 144.76.70.73:54425
2013-11-03 05:11:27 accepted connection 144.76.102.176:30757
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=176.9.144.41:32687, peer=176.9.144.41:32687
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=176.9.144.41:32687
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=46.4.64.21:56061, peer=46.4.64.21:56061
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=46.4.64.21:56061
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=5.9.30.207:42607, peer=5.9.30.207:42607
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=5.9.30.207:42607
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=144.76.70.73:54425, peer=144.76.70.73:54425
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=144.76.70.73:54425
2013-11-03 05:11:27 accepted connection 5.9.110.78:55205
2013-11-03 05:11:27 accepted connection 5.9.245.121:60001
2013-11-03 05:11:27 accepted connection 88.198.41.74:39240
2013-11-03 05:11:27 accepted connection 5.9.203.20:43255
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=144.76.102.176:30757, peer=144.76.102.176:30757
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=144.76.102.176:30757
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=5.9.110.78:55205, peer=5.9.110.78:55205
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=5.9.110.78:55205
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=5.9.245.121:60001, peer=5.9.245.121:60001
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=5.9.245.121:60001
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=88.198.41.74:39240, peer=88.198.41.74:39240
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=88.198.41.74:39240
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=5.9.203.20:43255, peer=5.9.203.20:43255
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=5.9.203.20:43255
2013-11-03 05:11:27 accepted connection 91.121.58.230:55388
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=91.121.58.230:55388, peer=91.121.58.230:55388
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=91.121.58.230:55388
2013-11-03 05:11:27 accepted connection 199.193.117.231:20562
2013-11-03 05:11:27 send version message: version 70001, blocks=267626, us=5.9.24.81:8333, them=199.193.117.231:20562, peer=199.193.117.231:20562
2013-11-03 05:11:27 receive version message: version 70001, blocks=1, us=127.0.0.1:8333, them=0.0.0.0:0, peer=199.193.117.231:20562
2013-11-03 05:11:32 ProcessMessages(ping, 0 bytes) : Exception 'CDataStream::read() : end of data' caught, normally caused by a message being shorter than its stated length
2013-11-03 05:11:32 ProcessMessage(ping, 0 bytes) FAILED

The thing is, I don't want to firewall these nodes as I receive blocks from some of them.  Anyone have any clue as to wtf the deal is?   Is there a way to stop this w/o firewalling the nodes themselves?  Does the message even matter?  Can I just ed -s debug.log <<< $'g/ProcessMessage/d\nw' it out of there or what?

It's the 'BS Satoshi 0.8.99' nodes.
Jump to: