echidna icon indicating copy to clipboard operation
echidna copied to clipboard

[Bug-Candidate]: Multiple seemingly related performance issues

Open rappie opened this issue 2 years ago • 7 comments

Describe the issue:

I'm encountering multiple seemingly related performance issues. It is a bit of a mess, but i'll try to over them one by one.

Using Foundry to compile

Command:

echidna . --contract PerformanceTest --test-mode assertion

Issue 1: When commenting out the fallback function

fallback() external payable virtual {}

performance drops from 10.000 calls/s to 1000 calls/s

image image

Issue 2: When commenting out the mapping assignment

MAPPING[address(0)] = 123;

performance drops from 10.000 calls/s to 2000 calls/s

Both of these effects are related to a third issue (see below). Using foundry to compiling (providing . to Echidna) needs issues 1 or 2 to trigger issue 3.

Using single file compilation

Command:

echidna src/PerformanceTest.sol --contract PerformanceTest --test-mode assertion

In this case issues 1&2 are not necessary to trigger issue 3.

Issue 3: Toggling between

contract A {
    // B b = new B();

    function a() public view returns (uint256) {
        return 1;
        // return b.a();
    }
}

and

contract A {
    B b = new B();

    function a() public view returns (uint256) {
        // return 1;
        return b.a();
    }
}

drops performance from 3500 calls/s to 1000 calls/s

I hope this makes sense and helps with debugging, it took a lot of work to figure this out. Please let me know if you have any questions or problems reproducing.

Code example to reproduce the issue:

https://github.com/rappie/echidna-debug-performance

// SPDX-License-Identifier: MIT
pragma solidity ^0.8.20;

abstract contract WithFallback {
    // fallback() external payable virtual {}
}

contract PerformanceTest {
    A a;

    mapping(address => uint256) internal MAPPING;

    constructor() {
        a = new A();
    }

    function test() public {
        // MAPPING[address(0)] = 123;
        uint256 result = a.a();
    }
}

contract A {
    B b = new B();

    function a() public view returns (uint256) {
        // return 1;
        return b.a();
    }
}

contract B {
    C c = new C();

    function a() public view returns (uint256) {
        return c.a();
    }
}

contract C {
    D d = new D();

    function a() public view returns (uint256) {
        return d.a();
    }
}

contract D {
    E e = new E();

    function a() public view returns (uint256) {
        return e.a();
    }
}

contract E {
    F f = new F();

    function a() public view returns (uint256) {
        return f.a();
    }
}

contract F {
    function a() public view returns (uint256) {
        return 1;
    }
}

Version:

Tested with multiple versions:

  • Latest master build using nix-env
  • Prebuilt 2.2.1
  • 2.2.0
  • 2.1.1

Using Manjaro Linux (arch based)

Relevant log output:

No response

rappie avatar Oct 31 '23 11:10 rappie

Output of slither . --print echidna

INFO:Printers:{
    "payable": {
        "WithFallback": [
            "()"
        ]
    },
    "timestamp": {},
    "block_number": {},
    "msg_sender": {},
    "msg_gas": {},
    "assert": {},
    "constant_functions": {
        "A": [
            "a()"
        ],
        "B": [
            "a()"
        ],
        "C": [
            "a()"
        ],
        "D": [
            "a()"
        ],
        "E": [
            "a()"
        ],
        "F": [
            "a()"
        ]
    },
    "constants_used": {
        "PerformanceTest": {
            "test()": [
                [
                    {
                        "value": "0",
                        "type": "address"
                    }
                ],
                [
                    {
                        "value": "123",
                        "type": "uint256"
                    }
                ]
            ]
        },
        "F": {
            "a()": [
                [
                    {
                        "value": "1",
                        "type": "uint256"
                    }
                ]
            ]
        }
    },
    "constants_used_in_binary": {},
    "functions_relations": {
        "WithFallback": {
            "()": {
                "impacts": [],
                "is_impacted_by": []
            }
        },
        "PerformanceTest": {
            "constructor()": {
                "impacts": [
                    "test()"
                ],
                "is_impacted_by": []
            },
            "test()": {
                "impacts": [],
                "is_impacted_by": [
                    "constructor()"
                ]
            }
        },
        "A": {
            "a()": {
                "impacts": [],
                "is_impacted_by": []
            }
        },
        "B": {
            "a()": {
                "impacts": [],
                "is_impacted_by": []
            }
        },
        "C": {
            "a()": {
                "impacts": [],
                "is_impacted_by": []
            }
        },
        "D": {
            "a()": {
                "impacts": [],
                "is_impacted_by": []
            }
        },
        "E": {
            "a()": {
                "impacts": [],
                "is_impacted_by": []
            }
        },
        "F": {
            "a()": {
                "impacts": [],
                "is_impacted_by": []
            }
        }
    },
    "constructors": {
        "PerformanceTest": "constructor()"
    },
    "have_external_calls": {
        "PerformanceTest": [
            "test()"
        ],
        "A": [
            "a()"
        ],
        "B": [
            "a()"
        ],
        "C": [
            "a()"
        ],
        "D": [
            "a()"
        ],
        "E": [
            "a()"
        ]
    },
    "call_a_parameter": {},
    "use_balance": {},
    "solc_versions": [
        "0.8.20"
    ],
    "with_fallback": [
        "WithFallback"
    ],
    "with_receive": []
}
INFO:Slither:. analyzed (8 contracts)

rappie avatar Oct 31 '23 12:10 rappie

@rappie can you test with the latest release?

gustavo-grieco avatar Mar 07 '24 17:03 gustavo-grieco

Yes. Just updated to the latest master. It will take some time to test this, if I encounter something i will share.

rappie avatar Mar 08 '24 11:03 rappie

I've tested it with the repo in this issue. All issues remain, but the general speed is a bit higher.

rappie avatar Mar 11 '24 13:03 rappie

Tried out these examples with the gas-per-second PR #1279 Mapping assignment uncommented: 57 million gas/second, 2600 calls/second Mapping assignment commented: 56 million gas/second, 2600 calls/second Return 1 uncommented, return b.a() commented, mapping assignment commented: 22 million gas/second, 16,600 calls/second

So:

  • The mapping assignment doesn't seem to have much of an effect anymore
  • Uncommenting the "return 1" increases the calls/sec by 8x, but lowers the gas/sec by 2.5x

samalws-tob avatar Jun 26 '24 20:06 samalws-tob

Not sure whether this indicates a performance problem or if this is just expected behavior. We would expect calls/sec to change when the gas-per-call changes. On the other hand we would expect gas/sec to be relatively stable, so a 2.5x variation in gas/sec between opcodes may point to a problem.

samalws-tob avatar Jun 26 '24 20:06 samalws-tob

Gas prices are probably tuned so that the gas/sec is even across each opcode in geth (ignoring storage requirements). So maybe the key question here is: how much difference between geth performance and hevm performance are we willing to tolerate?

samalws-tob avatar Jun 26 '24 20:06 samalws-tob