search

neo-project / neo

NEO Smart Economy
MIT License
3.47k stars 1.03k forks source link

Extend applicationlogs with invocations #3386

Open ixje opened 3 months ago

ixje commented 3 months ago

Summary or problem description Transactions can perform multiple contract calls in 1 script, or 1 contract call that performs internal calls to other smart contracts. The applicationlogs currently only return System.Runtime.Notify calls in the notifications list, but not all contracts emit notifications and therefore as a consumer we loose visibility of what has happened in the transaction.

Also, notifications do not always include all useful information e.g. for T5 tx 0x19bea71b2f6634bd2503099360a039799979e787f20826db0f1cf2e8b6e51af2 the applicationlog contains

{
    "contract": "0x49cf4e5378ffcd4dec034fd98a174c5491e395e2",
    "eventname": "Designation",
    "state": {
        "type": "Array",
        "value": [
            {
                "type": "Integer",
                "value": "4"
            },
            {
                "type": "Integer",
                "value": "3599"
            }
        ]
    }
}

All that we can derive from this notification is that at block 3599 the StateValidator role was assigned. But to who?

Do you have any solution you want to propose? I implemented a PoC for neo-go which captures all calls to the System.Contract.Call SYSCALL and appends these to the applicationlog. The application log for the above discussed T5 transaction becomes

{
    "id": 1,
    "jsonrpc": "2.0",
    "result": {
        "txid": "0x19bea71b2f6634bd2503099360a039799979e787f20826db0f1cf2e8b6e51af2",
        "executions": [
            {
                "trigger": "Application",
                "vmstate": "HALT",
                "gasconsumed": "209055",
                "stack": [
                    {
                        "type": "Any"
                    }
                ],
                "notifications": [
                    {
                        "contract": "0x49cf4e5378ffcd4dec034fd98a174c5491e395e2",
                        "eventname": "Designation",
                        "state": {
                            "type": "Array",
                            "value": [
                                {
                                    "type": "Integer",
                                    "value": "4"
                                },
                                {
                                    "type": "Integer",
                                    "value": "3599"
                                }
                            ]
                        }
                    }
                ],
                "exception": null,
                "invocations": [
                    {
                        "contract_hash": "0x49cf4e5378ffcd4dec034fd98a174c5491e395e2",
                        "method": "designateAsRole",
                        "parameters": {
                            "type": "Array",
                            "value": [
                                {
                                    "type": "Integer",
                                    "value": "4"
                                },
                                {
                                    "type": "Array",
                                    "value": [
                                        {
                                            "type": "ByteString",
                                            "value": "A0AcxP8tV4phfghLecnr6nOWP/Pe/3hS7cQrwenon4uf"
                                        },
                                        {
                                            "type": "ByteString",
                                            "value": "AojK1EKod5YMdrT2iPS+MPdoJW2aPaJJKwGAuRJDkYtP"
                                        },
                                        {
                                            "type": "ByteString",
                                            "value": "A5tFBAzFKZZhZe9d/z0EaklgUgzmFq4XDiZdZp4OLef0"
                                        },
                                        {
                                            "type": "ByteString",
                                            "value": "A9KvHTaxa+UMmyFzKXU1oBSowZEPWSh8XF3+hqBFzvXV"
                                        }
                                    ]
                                }
                            ]
                        }
                    }
                ]
            }
        ]
    }
}

With the information from the invocations list we can actually tell that the role was assigned to the following public keys:

This is just one of many scenarios where this information gives builders far more data and insights to work with.

Stats I've collected some information on how this change affects the chain size and performance. The information is collected for MainNet up to block 5607836 and for T5 up to block 4217754 synced from chain dumps obtained via sync.ngd.network

time
chain extended app logs real user sys chain size on disk in bytes
mainnet y 107m7.367s 198m22.133s 60m3.692s 54811032
mainnet n 101m48.200s 193m1.756s 57m38.710s 54276488
t5 y 35m6.453s 71m40.047s 18m59.119s 18939352
t5 n 35m29.732s 72m5.290s 19m8.286s 18908808

Mainnet chain size increased by 522 KB. Syncing speed took 319.167 seconds extra (based on real time). The chain has 5372363 transactions meaning that processing speed took 0.0594ms extra on average per tx.

T5 chain size increased by < 30KB. Syncing speed was actually faster by a couple of seconds but could be explained by i/o differences

Where in the software does this update applies to?

shargon commented 3 months ago

It should be good to have a trace method

AnnaShaleva commented 3 months ago

We have similar functionality for test invocations (a.k.a. Diagnostics, ref. https://github.com/neo-project/neo-modules/pull/657 and https://github.com/neo-project/neo-modules/pull/656#discussion_r729934698), it may probably be extended to include invocation parameters and then reused for application logs. And the statistics is useful, because I'd expect these data to be heavier than it's shown. So the proposal LGTM.

All that we can derive from this notification is that at block 3599 the StateValidator role was assigned. But to who?

I'd say that RoleManagement notifications may be a subject of improvement by their own. To me, it's worth to extend "Designation" notification with old/new public keys exactly like it's done with "CommitteeChanged" events. It's possible without resync, thanks to the native update functionality. What do you think?

cschuchardt88 commented 3 months ago

We could add this to DebugMode in the ApplicationLogs. Seeing how ApplicationLogs in DebugMode shows Log events

ixje commented 3 months ago

I'd say that RoleManagement notifications may be a subject of improvement by their own. To me, it's worth to extend "Designation" notification with old/new public keys exactly like it's done with "CommitteeChanged" events. It's possible without resync, thanks to the native update functionality. What do you think?

Sounds good. It's probably best to migrate that topic to a separate issue

ixje commented 3 months ago

We could add this to DebugMode in the ApplicationLogs. Seeing how ApplicationLogs in DebugMode shows Log events

What is DebugMode? I get 0 hits when searching for that.

cschuchardt88 commented 3 months ago

We could add this to DebugMode in the ApplicationLogs. Seeing how ApplicationLogs in DebugMode shows Log events

What is DebugMode? I get 0 hits when searching for that.

So far just adds LogEventArgs ("Runtime.Log" for contracts) to output in RPC for ApplicationLogs

Read more here https://github.com/neo-project/neo-modules/issues/841

ixje commented 3 months ago

I don't see any objections. Can we add this to the 3.8.0 milestone?

ixje commented 3 months ago

@roman-khimov @Jim8y @vncoelho can you please share your opinion on the idea?

ixje commented 3 months ago

ping @roman-khimov @Jim8y @vncoelho

vncoelho commented 3 months ago

I am in agreement with the feature. I think as a Debug flag of the module is good for the first moment. Regarding the deadline and milestone, we have a TC now that helps us to define some key points. Thus, it is not much up to me.

But as soon as the PR is created,you can count with me to review, analyze, and test.

roman-khimov commented 3 months ago

While I like the additional data we get and it doesn't seem to be very costly, I fear this can be abused. Imagine a script doing a number of calls in a loop with arrays in parameters. In some ways it's comparable to notifications (and the interop fee is the same), but notifications are specifically limited in many ways, while we can't really limit invocations. If we're to accept some potential data loss there (like technically this can already happen to the Stack component of application log) then we can have it (resynchronization included).