Web3.py: Padding bytes were not empty: 0x0000000000

[lpassos]

• Version: 3.16.4
• Python: 3.6.3
• OS: osx

What was wrong?

Calling a contract function expecting an address, a string, and an uint results in an error regarding padding. The function signature is

  function doSomething(address a, string b, uint256 c) external {
   // ....
  }

whereas the invocation is given by

 from web3 import Web3
 self.__cfg.internal_contract.transact({"from": self.__account}).doSomething(
            self.__account,
            b"abc",
            100,    
 )

When processing the event in a separate thread, I get the following:

  File "/usr/local/Cellar/python3/3.6.3/Frameworks/Python.framework/Versions/3.6/lib/python3.6/threading.py", line 916, in _bootstrap_inner
    self.run()
  File "/usr/local/Cellar/python3/3.6.3/Frameworks/Python.framework/Versions/3.6/lib/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.6/site-packages/web3/utils/filters.py", line 91, in _run
    callback_fn(self.format_entry(entry))
  File "/usr/local/lib/python3.6/site-packages/web3/utils/filters.py", line 206, in format_entry
    return self.log_entry_formatter(entry)
  File "/usr/local/lib/python3.6/site-packages/eth_utils/string.py", line 85, in inner
    return force_obj_to_text(fn(*args, **kwargs))
  File "/usr/local/lib/python3.6/site-packages/web3/utils/events.py", line 176, in get_event_data
    decoded_log_data = decode_abi(log_data_types, log_data)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/abi.py", line 109, in decode_abi
    return decoder(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 102, in __call__
    return self.decode(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_utils/functional.py", line 22, in inner
    return callback(fn(*args, **kwargs))
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 140, in decode
    yield decoder(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 102, in __call__
    return self.decode(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 168, in decode
    cls.validate_padding_bytes(value, padding_bytes)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 274, in validate_padding_bytes
    "Padding bytes were not empty: {0}".format(force_text(padding_bytes))
eth_abi.exceptions.NonEmptyPaddingBytes: Padding bytes were not empty: 0x0000000000

Any ideas?

[lpassos]

For the record, changing the function modifier to public seems to do the work. But still, why is external failing?

[pipermerriam]

The error here (from looking at the stack trace) looks like it's due to trying to decode the log data and failing. @dylanjw I think this may concern you as we might need to add some failsafes into the rich log decoding to handle invalid log entries assuming that is the case. @lpassos to really debug this we'll need so more information to be able to reproduce it locally.

• minimal contract code that produces this error.
• compiler version for that code.
• ideally minimal python script that produces the error.

[carver]

For the record, changing the function modifier to public seems to do the work. But still, why is external failing?

That is interesting. Looks like external is a test case that should be added. @lpassos can you provide the repro steps that Piper mentioned?

[lpassos]

Here is how to reproduce the bug:

#########
# test.py
#########
from web3 import Web3, TestRPCProvider
from solc import compile_files

# Creates the target contract object

def init_test():
    src_contract = "./test.sol"
    contract_name = 'SimpleTest'

    contract_dict = compile_files([src_contract])

    contract_id = "{0}:{1}".format(
        src_contract,
        contract_name,
    )

    contract_interface = contract_dict[contract_id]

    w3 = Web3(TestRPCProvider())

    contract_instance = w3.eth.contract(
        abi = contract_interface['abi'],
        bytecode = contract_interface['bin'],
    )

    account = w3.eth.accounts[0]

    transaction_hash = contract_instance.deploy(transaction = {'from': account})

    receipt = w3.eth.getTransactionReceipt(transaction_hash)
    contract_address = receipt['contractAddress']

    return w3.eth.contract(
        contract_interface['abi'], 
        contract_address
    ), account 

def main():
    contract, account = init_test()

    filter = contract.on("LogAction")

    contract.transact({"from": account}).doSomething(
        account, 
        "foo",
        100,
    )

    while True:
        evts = filter.get()
        if evts != []:
            print("Events found: " + str(evts))
            break

if __name__ == "__main__":
    main()

The test.sol file is defined as:

/*########
  test.sol
 *########*/

pragma solidity 0.4.18;

contract SimpleTest {
    event LogAction(address x, string y, uint256 z);

    function doSomething(address x, string y, uint256 z) external {
        LogAction(x, y, z);
    }
}

Executing test.py should generate a stack trace like the following:

  File "test.py", line 56, in <module>
    main()
  File "test.py", line 50, in main
    evts = filter.get()
  File "/usr/local/lib/python3.6/site-packages/web3/utils/filters.py", line 200, in get
    self.format_entry(log_entry) for log_entry in log_entries
  File "/usr/local/lib/python3.6/site-packages/web3/utils/filters.py", line 200, in <listcomp>
    self.format_entry(log_entry) for log_entry in log_entries
  File "/usr/local/lib/python3.6/site-packages/web3/utils/filters.py", line 206, in format_entry
    return self.log_entry_formatter(entry)
  File "/usr/local/lib/python3.6/site-packages/eth_utils/string.py", line 85, in inner
    return force_obj_to_text(fn(*args, **kwargs))
  File "/usr/local/lib/python3.6/site-packages/web3/utils/events.py", line 176, in get_event_data
    decoded_log_data = decode_abi(log_data_types, log_data)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/abi.py", line 109, in decode_abi
    return decoder(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 102, in __call__
    return self.decode(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_utils/functional.py", line 22, in inner
    return callback(fn(*args, **kwargs))
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 140, in decode
    yield decoder(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 102, in __call__
    return self.decode(stream)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 168, in decode
    cls.validate_padding_bytes(value, padding_bytes)
  File "/usr/local/lib/python3.6/site-packages/eth_abi/decoding.py", line 274, in validate_padding_bytes
    "Padding bytes were not empty: {0}".format(force_text(padding_bytes))
eth_abi.exceptions.NonEmptyPaddingBytes: Padding bytes were not empty: 0x0000000000

But now try changing

function doSomething(address x, string y, uint256 z) external

to

function doSomething(address x, string y, uint256 z) public

and the exception is gone.

[carver]

:+1: Reproduced locally, also confirmed in:

• web3 versions
  
  
  
  • v3.16.5
  
  
  • v4b7
  
  
• Solidity compiler 0.4.19.
• EthereumTesterProvider (different error, but same conditions: only breaks with external modifier)

I have no idea what this is yet, but we have everything we need to investigate. I won't be able to put much time into it until early next week.

[lpassos]

Hey @carver, any updates?

[carver]

Not yet, I had some other fires to put out. I will hopefully get a chance before the end of the week.

[pipermerriam]

FYI, there is a larger separate issue that I don't think has been discussed and I don't think we currently handle.

When parsing log data, we assume that because the first topic matches the topic derived from the event signature, that it will be well-formed for decoding via the ABI for the given event. This assumption is easily broken. It's trivial to log an event with the first topic matching a known event API but to include arbitrary or junk data for any of the subsequent topics or data values.

We should figure out how to handle this as it's a griefing vector. I could litter the blockchain with events that matche the ERC20 Transfer event but with data that will blow up the decoder. This would crash people using web3.py to monitor the chain for ERC20 Transfer events which is generally bad.

[carver]

Summary

So it took me quite a lot of testing to believe this, but the events get logged differently if the function is external vs public. The public one has trailing 0s. That surprised me.

It makes no sense to me that the logged event data would be different, depending on whether it was logged by a public function or an external function. This and this are pretty much all I know about external functions, so far, though. So it's on my todo list to go get less clueless about external.

But web3.js can parse both versions of the data. So the next step seems to be figuring out what web3.js is doing, and see if that's consistent with other protocol docs, eth-abi, etc.

Web3.py Test Results

Web3.py fails to parse the external logs with every node I tested: py-evm via eth-tester, eth-testrpc, and geth --dev.

For example, with geth and a public function, I send this transaction and get this log data back:

[{
  'from': '0x39708c52AEa50be256bcCd350D043ff36fFbb0E6',
  'to': '0xb39118Eb54134bf070137219f85BA3AeD2D01043',
  'data': '0xd68c480e00000000000000000000000039708c52aea50be256bccd350d043ff36ffbb0e6000000000000000000000000000000000000000000000000000000000000006000000000000000000000000000000000000000000000000000000000000000640000000000000000000000000000000000000000000000000000000000000003666f6f0000000000000000000000000000000000000000000000000000000000'
}]
0x00000000000000000000000039708c52aea50be256bccd350d043ff36ffbb0e6000000000000000000000000000000000000000000000000000000000000006000000000000000000000000000000000000000000000000000000000000000640000000000000000000000000000000000000000000000000000000000000003666f6f0000000000000000000000000000000000000000000000000000000000

With geth and an external function, I send the same transaction and get this log data back:

[{
  'from': '0x39708c52AEa50be256bcCd350D043ff36fFbb0E6',
  'to': '0x73FAf3Ad82749fFE352b161f4effaf7CBc98de91',
  'data': '0xd68c480e00000000000000000000000039708c52aea50be256bccd350d043ff36ffbb0e6000000000000000000000000000000000000000000000000000000000000006000000000000000000000000000000000000000000000000000000000000000640000000000000000000000000000000000000000000000000000000000000003666f6f0000000000000000000000000000000000000000000000000000000000'
}]
0x00000000000000000000000039708c52aea50be256bccd350d043ff36ffbb0e6000000000000000000000000000000000000000000000000000000000000006000000000000000000000000000000000000000000000000000000000000000640000000000000000000000000000000000000000000000000000000000000003666f6f

Note the lack of trailing 0s in the external version ^ -- That is the only difference.

These data were collected from the IPC source, without any middleware/formatting, etc.

Web3.js Test Results

Again, the receipt logs show the same raw data for each scenario (with trailing 0s for public). But web3.js parses it fine either way.

Public:

> publicTest = SimpleTestPublic.at('0xb39118Eb54134bf070137219f85BA3AeD2D01043')
> publicTest.allEvents().get()
[{
    address: "0xb39118eb54134bf070137219f85ba3aed2d01043",
    args: {
      x: "0x39708c52aea50be256bccd350d043ff36ffbb0e6",
      y: "foo",
      z: 100
    },
    blockHash: "0xf28c5818a425d4d054447c8e4eeeef7dafcfc8737b74139ff87217cef411fe88",
    blockNumber: 18,
    event: "LogAction",
    logIndex: 0,
    removed: false,
    transactionHash: "0xf9b559f88e47448d1861a64831fbc4696ac549219ae0b183396f005b708b0d6e",
    transactionIndex: 0
}]

External:

> externalTest = SimpleTestExternal.at('0x73FAf3Ad82749fFE352b161f4effaf7CBc98de91')
> externalTest.allEvents().get()
[{
    address: "0x73faf3ad82749ffe352b161f4effaf7cbc98de91",
    args: {
      x: "0x39708c52aea50be256bccd350d043ff36ffbb0e6",
      y: "foo",
      z: 100
    },
    blockHash: "0x925bb1ad4966c67b7802f9b9e368c1007b7558b72d8787aa37adbdde2937a382",
    blockNumber: 17,
    event: "LogAction",
    logIndex: 0,
    removed: false,
    transactionHash: "0x4ceb686ff9c1afd69f535e9ec129257b70ec4091b5e1cc27b4541d69b70670c8",
    transactionIndex: 0
}]

[carver]

Whelp, I have no idea. I just wrote it up: https://ethereum.stackexchange.com/questions/39418/why-do-public-and-external-functions-emit-strings-differently-in-event-logs

It sure seems like the external version is producing invalid ABI. Hopefully I'll be corrected.

[pipermerriam]

"It's never a compiler bug" ..... ☹️

[lpassos]

So, what can I conclude from this conversation? By the way, is there any way I can help?

[pipermerriam]

@lpassos it is a bug in solidity: https://github.com/ethereum/solidity/issues/3493