ethereum / go-ethereum

Go implementation of the Ethereum protocol
https://geth.ethereum.org
GNU Lesser General Public License v3.0
47.07k stars 19.95k forks source link

Mobile: Bad Packet when connecting to private chain #3638

Closed Omnidip closed 7 years ago

Omnidip commented 7 years ago

System information

Geth version: 1.5.8 OS & Version: Windows/Linux/OSX/Android Commit hash : f58fb32283fe04cd1d416040c6692b4a7352d556

Note: Android client running on an emulator, Node running on the host

Expected behaviour

ping and pong packets should be being sent back and forth between the local node and the android client.

Actual behaviour

discv5/udp.go spits out the errors: E/GoLog: I0202 20:01:53.926344 p2p/discv5/udp.go:410] Bad packet from 10.0.2.2:30305: rlp: too few elements for discv5.pong E/GoLog: I0202 20:01:53.929642 p2p/discv5/udp.go:410] Bad packet from 10.0.2.2:30305: rlp: too few elements for discv5.ping E/GoLog: I0202 20:01:54.397246 p2p/discv5/net.go:461] --- (0) pongTimeout for f219c0645bffbf64@10.0.2.2:30305: verifyinit -> unknown (ok) then stops trying to connect with the local node.

NOTE: This does NOT happen when trying to connect to the discv5 bootnodes within params/bootnodes.go, those produce the expected behaviour

Steps to reproduce the behaviour

Create a local node with genesis:

{ 
    "nonce": "0x0000004857738350273500",
    "timestamp": "0x0",
    "parentHash": "0x0000000000000000000000000000000000000000000000000000000000000000",
    "extraData": "0x0",
    "gasLimit": "0x8000000",
    "difficulty": "0x40",
    "mixhash": "0x0000000000000000000000000000000000000000000000000000000000000000",
    "coinbase": "0x3333333333333333333333333333333333333356",
    "alloc": {}
}

Create an android project with the onCreate:

`protected void onCreate(Bundle savedInstanceState) { super.onCreate(savedInstanceState); setContentView(R.layout.activity_main); final TextView textbox = (TextView) findViewById(R.id.show_text);

    setTitle("Android In-Process Node");

    Context ctx = new Context();

    try {

        Enodes bootstrap = new Enodes(1);
        Enode mainBootstrap = Geth.newEnode("enode://<ENODE_ID>@10.0.2.2:<PORT>");
        bootstrap.set(0, mainBootstrap);

        NodeConfig config = new NodeConfig();
        config.setBootstrapNodes(bootstrap);
        config.setMaxPeers(15);
        config.setEthereumEnabled(true);
        config.setEthereumNetworkID(413);
        config.setEthereumDatabaseCache(512);
        config.setWhisperEnabled(false);

        Geth.setVerbosity(6);

        config.setEthereumGenesis(" {\n" +
                "    \"nonce\": \"0x0000004857738350273500\",\n" +
                "    \"timestamp\": \"0x0\",\n" +
                "    \"parentHash\": \"0x0000000000000000000000000000000000000000000000000000000000000000\",\n" +
                "    \"extraData\": \"0x0\",\n" +
                "    \"gasLimit\": \"0x8000000\",\n" +
                "    \"difficulty\": \"0x40\",\n" +
                "    \"mixhash\": \"0x0000000000000000000000000000000000000000000000000000000000000000\",\n" +
                "    \"coinbase\": \"0x3333333333333333333333333333333333333356\",\n" +
                "    \"alloc\": {} \n" +
                "}\n");

        Node node = Geth.newNode(getFilesDir() + ".ethereum", config);
        node.start();

        EthereumClient ec = node.getEthereumClient();
        textbox.append("Latest Block: " + ec.getBlockByNumber(ctx, -1).getNumber() + " syncing...");
        textbox.append("Count Peers: " + node.getPeersInfo().size() + "\n\n");

        NewHeadHandler handler = new NewHeadHandler() {
            @Override
            public void onError(String error) {
            }

            @Override
            public void onNewHead(final Header header) {
                MainActivity.this.runOnUiThread(new Runnable() {
                    public void run() {
                        textbox.append("#" + header.getNumber() + ": " + header.getHash().getHex().substring(0, 10) + "…\n");
                    }
                });
            }
        };
        ec.subscribeNewHead(ctx, handler, 16);

    } catch (Exception e) {
        e.printStackTrace();
    }
}`

Backtrace

E/GoLog: I0202 20:01:53.866071 node/node.go:176] instance: GethDroid/v1.5.8-stable/android/go1.7.4
E/GoLog: I0202 20:01:53.866170 ethdb/database.go:83] Allotted 512MB cache and 16 file handles to /data/user/0/projectTest/files.ethereum/GethDroid/lightchaindata
E/GoLog: I0202 20:01:53.887397 core/state/statedb.go:605] Trie cache stats: 0 misses, 0 unloads
E/GoLog: I0202 20:01:53.887655 core/database_util.go:385] stored block total difficulty [dd926915…]: 64
E/GoLog: I0202 20:01:53.887733 core/database_util.go:371] stored block body [dd926915…]
E/GoLog: I0202 20:01:53.887803 core/database_util.go:352] stored header #0 [dd926915…]
E/GoLog: I0202 20:01:53.887839 core/database_util.go:420] stored block receipts [dd926915…]
E/GoLog: I0202 20:01:53.887873 eth/backend.go:276] Successfully wrote custom genesis block: dd9269151323d70736aa9b81982830b3fef8a8db1550d9f84c659fae8fb45caf
E/GoLog: I0202 20:01:53.888300 light/lightchain.go:172] Last header: #0 [dd926915…] TD=64
E/GoLog: I0202 20:01:53.888335 core/database_util.go:385] stored block total difficulty [dd926915…]: 64
E/GoLog: I0202 20:01:53.888360 core/database_util.go:371] stored block body [dd926915…]
E/GoLog: I0202 20:01:53.888418 core/database_util.go:352] stored header #0 [dd926915…]
E/GoLog: I0202 20:01:53.888533 light/lightchain.go:172] Last header: #0 [dd926915…] TD=64
E/GoLog: I0202 20:01:53.888607 les/handler.go:202] LES: create downloader
E/GoLog: I0202 20:01:53.888680 p2p/server.go:340] Starting Server
E/GoLog: I0202 20:01:53.893464 eth/downloader/downloader.go:1474] Quality of service: rtt 20s, conf 1.000, ttl 1m0s
E/GoLog: I0202 20:01:53.895526 p2p/discv5/net.go:700] seed node (age 412796h1m53.895514844s): enode://f219c0645bffbf643096b7718033a894ebacd652fec90c47af707e25c7877a0e720485cb9a31f44ac7d3397e79061e0821911b0357248d70db39a878e318dc8f@10.0.2.2:30305
E/GoLog: I0202 20:01:53.896597 p2p/discv5/udp.go:351] >>> pingPacket to f219c0645bffbf64@10.0.2.2:30305
E/GoLog: I0202 20:01:53.896828 les/backend.go:191] WARNING: light client mode is an experimental feature
E/GoLog: I0202 20:01:53.897012 node/node.go:304] InProc registered *node.PrivateAdminAPI under 'admin'
E/GoLog: I0202 20:01:53.897049 node/node.go:304] InProc registered *node.PublicAdminAPI under 'admin'
E/GoLog: I0202 20:01:53.897158 node/node.go:304] InProc registered *debug.HandlerT under 'debug'
E/GoLog: I0202 20:01:53.897182 node/node.go:304] InProc registered *node.PublicDebugAPI under 'debug'
E/GoLog: I0202 20:01:53.897203 node/node.go:304] InProc registered *node.PublicWeb3API under 'web3'
E/GoLog: I0202 20:01:53.897223 node/node.go:304] InProc registered *ethapi.PublicCompilerAPI under 'eth'
E/GoLog: I0202 20:01:53.897243 node/node.go:304] InProc registered *ethapi.CompilerAdminAPI under 'admin'
E/GoLog: I0202 20:01:53.897276 node/node.go:304] InProc registered *ethapi.PublicEthereumAPI under 'eth'
E/GoLog: I0202 20:01:53.897443 node/node.go:304] InProc registered *ethapi.PublicBlockChainAPI under 'eth'
E/GoLog: I0202 20:01:53.897612 node/node.go:304] InProc registered *ethapi.PublicTransactionPoolAPI under 'eth'
E/GoLog: I0202 20:01:53.897644 node/node.go:304] InProc registered *ethapi.PublicTxPoolAPI under 'txpool'
E/GoLog: I0202 20:01:53.897674 node/node.go:304] InProc registered *ethapi.PublicDebugAPI under 'debug'
E/GoLog: I0202 20:01:53.897710 node/node.go:304] InProc registered *ethapi.PrivateDebugAPI under 'debug'
E/GoLog: I0202 20:01:53.897725 node/node.go:304] InProc registered *ethapi.PublicAccountAPI under 'eth'
E/GoLog: I0202 20:01:53.897792 node/node.go:304] InProc registered *ethapi.PrivateAccountAPI under 'personal'
E/GoLog: I0202 20:01:53.897823 node/node.go:304] InProc registered *les.LightDummyAPI under 'eth'
E/GoLog: I0202 20:01:53.897845 node/node.go:304] InProc registered *downloader.PublicDownloaderAPI under 'eth'
E/GoLog: I0202 20:01:53.897910 node/node.go:304] InProc registered *filters.PublicFilterAPI under 'eth'
E/GoLog: I0202 20:01:53.897932 node/node.go:304] InProc registered *ethapi.PublicNetAPI under 'net'
E/GoLog: I0202 20:01:53.898107 p2p/server.go:608] Listening on [::]:60859
E/GoLog: I0202 20:01:53.902645 rpc/client.go:412] sending {"jsonrpc":"2.0","id":1,"method":"eth_getBlockByNumber","params":["latest",true]}
E/GoLog: I0202 20:01:53.903970 rpc/client.go:505] <-readResp: response {"jsonrpc":"2.0","id":1,"result":{"difficulty":"0x40","extraData":"0x00","gasLimit":"0x8000000","gasUsed":"0x0","hash":"0xdd9269151323d70736aa9b81982830b3fef8a8db1550d9f84c659fae8fb45caf","logsBloom":"0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","miner":"0x3333333333333333333333333333333333333334","mixHash":"0x0000000000000000000000000000000000000000000000000000000000000000","nonce":"0x4857038450293400","number":"0x0","parentHash":"0x00000000000000000000000000000000000000000000000000000
E/GoLog: 00000000000","receiptsRoot":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","sha3Uncles":"0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347","size":"0x1f9","stateRoot":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","timestamp":"0x0","totalDifficulty":"0x40","transactions":[],"transactionsRoot":"0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421","uncles":[]}}
E/GoLog: I0202 20:01:53.905774 rpc/client.go:412] sending {"jsonrpc":"2.0","id":2,"method":"eth_subscribe","params":["newHeads",{}]}
E/GoLog: I0202 20:01:53.906062 rpc/client.go:505] <-readResp: response {"jsonrpc":"2.0","id":2,"result":"0x3fe0412c7a94e915ffcad1487800293c"}
E/GoLog: I0202 20:01:53.926344 p2p/discv5/udp.go:410] Bad packet from 10.0.2.2:30305: rlp: too few elements for discv5.pong
E/GoLog: I0202 20:01:53.929642 p2p/discv5/udp.go:410] Bad packet from 10.0.2.2:30305: rlp: too few elements for discv5.ping
E/GoLog: I0202 20:01:54.397246 p2p/discv5/net.go:461] --- (0) pongTimeout for f219c0645bffbf64@10.0.2.2:30305: verifyinit -> unknown (ok)
E/GoLog: I0202 20:01:56.025737 p2p/nat/nat.go:111] mapped network port tcp:60859 -> 60859 (ethereum p2p) using UPNP IGDv1-PPP1
sekharkumarroy commented 7 years ago

Hi, I'm getting the same issue while connecting a mobile geth light client. Did you get any luck connecting to private-net ? Error is "(0) pongTimeout for 50eed70dc26bd864@XX.XX.XX.XX:31113: verifyinit -> unknown (ok)" Any help is greatly appreciated.

beatrizsanchez commented 7 years ago

I am having the same issue in Ubuntu when trying to connect to a bootnode in a private network where the node uses --light --v5disc modes. This is the error I have on the discovery with the previous configuration:

msg="--- (0) pongTimeout for ID@XX.XX.XX.XX:30301: verifyinit -> unknown (ok)"

However, I have the same problem with protocol v4 :

New dial task                            task="discovery lookup"
Starting bonding ping/pong               id=X **known=false** failcount=0 age=X
>> PING/v4                               addr=XX.XX.XX.XX:30301 err=nil
No discv4 seed nodes found 
Dial task done                           task="discovery lookup"

I am running the latest version of geth.

I also think that the --v5 on the bootnode does not work properly: it takes ages to start, if it actually does...

fjl commented 7 years ago

@MondyWins please stop posting this type of question on our issue tracker

karalabe commented 7 years ago

The issue is that you are trying to connect to the v4 discovery port with the light client. To connect to v5, you need to explicitly specify the discovery port number in the enode url, which will be 1 higher than the normal port number.

E.g. For rinkeby it's enode://a24ac7c5484ef4ed0c5eb2d36620ba4e4aa13b8c84684e1b4aab0cebea2ae45cb4d375b77eab56516d34bfbd3c1a833fc51296ff084b770b94fb9028c4d25ccf@52.169.42.101:30303?discport=30304