exception seen in witness logs

prandnum commented

2022-01-13 17:03:58 +00:00

(Migrated from gitlab.com)

The exception was seen in witness logs(hetzner vm):

2694217ms th_a db_notify.cpp:615 notify_applied_block ] Caught unexpected exception in plugin

2670212ms th_a       application.cpp:460           handle_block         ] Got block: #46498084 time: 2022-01-13T16:44:30 latency: 212 ms from: miss-jana  irreversible: 46498075 (-9)
2673212ms th_a       application.cpp:460           handle_block         ] Got block: #46498085 time: 2022-01-13T16:44:33 latency: 212 ms from: robert-hedler  irreversible: 46498076 (-9)
2679039ms th_a       application.cpp:460           handle_block         ] Got block: #46498086 time: 2022-01-13T16:44:39 latency: 38 ms from: jogersenjo1  irreversible: 46498076 (-10)
2682225ms th_a       application.cpp:460           handle_block         ] Got block: #46498087 time: 2022-01-13T16:44:42 latency: 224 ms from: viazi-vidogo  irreversible: 46498079 (-8)
2685027ms th_a       application.cpp:460           handle_block         ] Got block: #46498088 time: 2022-01-13T16:44:45 latency: 27 ms from: eifos-witness  irreversible: 46498080 (-8)
2688033ms th_a       application.cpp:460           handle_block         ] Got block: #46498089 time: 2022-01-13T16:44:48 latency: 33 ms from: houdini-witness  irreversible: 46498081 (-8)
2690828ms th_a       application.cpp:509           handle_transaction   ] Got 7 transactions from network
2691401ms th_a       application.cpp:460           handle_block         ] Got block: #46498090 time: 2022-01-13T16:44:51 latency: 401 ms from: viazi-vidogo  irreversible: 46498082 (-8)
2694215ms th_a       application.cpp:460           handle_block         ] Got block: #46498091 time: 2022-01-13T16:44:54 latency: 215 ms from: robert-hedler  irreversible: 46498082 (-9)
2694217ms th_a       db_notify.cpp:615             notify_applied_block ] Caught unexpected exception in plugin
2697213ms th_a       application.cpp:460           handle_block         ] Got block: #46498092 time: 2022-01-13T16:44:57 latency: 212 ms from: wit-super  irreversible: 46498082 (-10)
2700032ms th_a       application.cpp:460           handle_block         ] Got block: #46498093 time: 2022-01-13T16:45:00 latency: 32 ms from: houdini-witness  irreversible: 46498083 (-10)
2706212ms th_a       application.cpp:460           handle_block         ] Got block: #46498094 time: 2022-01-13T16:45:06 latency: 212 ms from: miss-jana  irreversible: 46498083 (-11)
2709217ms th_a       application.cpp:460           handle_block         ] Got block: #46498095 time: 2022-01-13T16:45:09 latency: 217 ms from: init0  irreversible: 46498083 (-12)
2712147ms th_a       application.cpp:460           handle_block         ] Got block: #46498096 time: 2022-01-13T16:45:12 latency: 147 ms from: hiltos-witness  irreversible: 46498086 (-10)
2715219ms th_a       application.cpp:460           handle_block         ] Got block: #46498097 time: 2022-01-13T16:45:15 latency: 219 ms from: salah8kassab  irreversible: 46498088 (-9)
2718030ms th_a       application.cpp:460           handle_block         ] Got block: #46498098 time: 2022-01-13T16:45:18 latency: 29 ms from: eifos-witness  irreversible: 46498090 (-8)
2721039ms th_a       application.cpp:460           handle_block         ] Got block: #46498099 time: 2022-01-13T16:45:21 latency: 39 ms from: jogersenjo1  irreversible: 46498091 (-8)
2724223ms th_a       application.cpp:460           handle_block         ] Got block: #46498100 time: 2022-01-13T16:45:24 latency: 223 ms from: viazi-vidogo  irreversible: 46498092 (-8)
2727213ms th_a       application.cpp:460           handle_block         ] Got block: #46498101 time: 2022-01-13T16:45:27 latency: 213 ms from: miss-jana  irreversible: 46498093 (-8)

A different witness(AWS VM) didn't have this exception in the logs at the same time. The effect of the above exception is not known

2670042ms th_a       application.cpp:460           handle_block         ] Got block: #46498084 time: 2022-01-13T16:44:30 latency: 42 ms from: miss-jana  irreversible: 46498075 (-9)
2673043ms th_a       application.cpp:460           handle_block         ] Got block: #46498085 time: 2022-01-13T16:44:33 latency: 43 ms from: robert-hedler  irreversible: 46498076 (-9)
2679172ms th_a       application.cpp:460           handle_block         ] Got block: #46498086 time: 2022-01-13T16:44:39 latency: 172 ms from: jogersenjo1  irreversible: 46498076 (-10)
2682077ms th_a       application.cpp:460           handle_block         ] Got block: #46498087 time: 2022-01-13T16:44:42 latency: 77 ms from: viazi-vidogo  irreversible: 46498079 (-8)
2685165ms th_a       application.cpp:460           handle_block         ] Got block: #46498088 time: 2022-01-13T16:44:45 latency: 165 ms from: eifos-witness  irreversible: 46498080 (-8)
2688131ms th_a       application.cpp:460           handle_block         ] Got block: #46498089 time: 2022-01-13T16:44:48 latency: 131 ms from: houdini-witness  irreversible: 46498081 (-8)
2690804ms th_a       application.cpp:509           handle_transaction   ] Got 7 transactions from network
2691134ms th_a       application.cpp:460           handle_block         ] Got block: #46498090 time: 2022-01-13T16:44:51 latency: 134 ms from: viazi-vidogo  irreversible: 46498082 (-8)
2694044ms th_a       application.cpp:460           handle_block         ] Got block: #46498091 time: 2022-01-13T16:44:54 latency: 44 ms from: robert-hedler  irreversible: 46498082 (-9)
2697042ms th_a       application.cpp:460           handle_block         ] Got block: #46498092 time: 2022-01-13T16:44:57 latency: 42 ms from: wit-super  irreversible: 46498082 (-10)
2700131ms th_a       application.cpp:460           handle_block         ] Got block: #46498093 time: 2022-01-13T16:45:00 latency: 131 ms from: houdini-witness  irreversible: 46498083 (-10)
2706043ms th_a       application.cpp:460           handle_block         ] Got block: #46498094 time: 2022-01-13T16:45:06 latency: 43 ms from: miss-jana  irreversible: 46498083 (-11)
2709043ms th_a       application.cpp:460           handle_block         ] Got block: #46498095 time: 2022-01-13T16:45:09 latency: 43 ms from: init0  irreversible: 46498083 (-12)
2712039ms th_a       application.cpp:460           handle_block         ] Got block: #46498096 time: 2022-01-13T16:45:12 latency: 39 ms from: hiltos-witness  irreversible: 46498086 (-10)
2715049ms th_a       application.cpp:460           handle_block         ] Got block: #46498097 time: 2022-01-13T16:45:15 latency: 49 ms from: salah8kassab  irreversible: 46498088 (-9)
2718168ms th_a       application.cpp:460           handle_block         ] Got block: #46498098 time: 2022-01-13T16:45:18 latency: 168 ms from: eifos-witness  irreversible: 46498090 (-8)
2721172ms th_a       application.cpp:460           handle_block         ] Got block: #46498099 time: 2022-01-13T16:45:21 latency: 172 ms from: jogersenjo1  irreversible: 46498091 (-8)
2724078ms th_a       application.cpp:460           handle_block         ] Got block: #46498100 time: 2022-01-13T16:45:24 latency: 78 ms from: viazi-vidogo  irreversible: 46498092 (-8)
2727043ms th_a       application.cpp:460           handle_block         ] Got block: #46498101 time: 2022-01-13T16:45:27 latency: 43 ms from: miss-jana  irreversible: 46498093 (-8)

The exception was seen in witness logs(hetzner vm): 2694217ms th_a db_notify.cpp:615 notify_applied_block ] Caught unexpected exception in plugin ``` 2670212ms th_a application.cpp:460 handle_block ] Got block: #46498084 time: 2022-01-13T16:44:30 latency: 212 ms from: miss-jana irreversible: 46498075 (-9) 2673212ms th_a application.cpp:460 handle_block ] Got block: #46498085 time: 2022-01-13T16:44:33 latency: 212 ms from: robert-hedler irreversible: 46498076 (-9) 2679039ms th_a application.cpp:460 handle_block ] Got block: #46498086 time: 2022-01-13T16:44:39 latency: 38 ms from: jogersenjo1 irreversible: 46498076 (-10) 2682225ms th_a application.cpp:460 handle_block ] Got block: #46498087 time: 2022-01-13T16:44:42 latency: 224 ms from: viazi-vidogo irreversible: 46498079 (-8) 2685027ms th_a application.cpp:460 handle_block ] Got block: #46498088 time: 2022-01-13T16:44:45 latency: 27 ms from: eifos-witness irreversible: 46498080 (-8) 2688033ms th_a application.cpp:460 handle_block ] Got block: #46498089 time: 2022-01-13T16:44:48 latency: 33 ms from: houdini-witness irreversible: 46498081 (-8) 2690828ms th_a application.cpp:509 handle_transaction ] Got 7 transactions from network 2691401ms th_a application.cpp:460 handle_block ] Got block: #46498090 time: 2022-01-13T16:44:51 latency: 401 ms from: viazi-vidogo irreversible: 46498082 (-8) 2694215ms th_a application.cpp:460 handle_block ] Got block: #46498091 time: 2022-01-13T16:44:54 latency: 215 ms from: robert-hedler irreversible: 46498082 (-9) 2694217ms th_a db_notify.cpp:615 notify_applied_block ] Caught unexpected exception in plugin 2697213ms th_a application.cpp:460 handle_block ] Got block: #46498092 time: 2022-01-13T16:44:57 latency: 212 ms from: wit-super irreversible: 46498082 (-10) 2700032ms th_a application.cpp:460 handle_block ] Got block: #46498093 time: 2022-01-13T16:45:00 latency: 32 ms from: houdini-witness irreversible: 46498083 (-10) 2706212ms th_a application.cpp:460 handle_block ] Got block: #46498094 time: 2022-01-13T16:45:06 latency: 212 ms from: miss-jana irreversible: 46498083 (-11) 2709217ms th_a application.cpp:460 handle_block ] Got block: #46498095 time: 2022-01-13T16:45:09 latency: 217 ms from: init0 irreversible: 46498083 (-12) 2712147ms th_a application.cpp:460 handle_block ] Got block: #46498096 time: 2022-01-13T16:45:12 latency: 147 ms from: hiltos-witness irreversible: 46498086 (-10) 2715219ms th_a application.cpp:460 handle_block ] Got block: #46498097 time: 2022-01-13T16:45:15 latency: 219 ms from: salah8kassab irreversible: 46498088 (-9) 2718030ms th_a application.cpp:460 handle_block ] Got block: #46498098 time: 2022-01-13T16:45:18 latency: 29 ms from: eifos-witness irreversible: 46498090 (-8) 2721039ms th_a application.cpp:460 handle_block ] Got block: #46498099 time: 2022-01-13T16:45:21 latency: 39 ms from: jogersenjo1 irreversible: 46498091 (-8) 2724223ms th_a application.cpp:460 handle_block ] Got block: #46498100 time: 2022-01-13T16:45:24 latency: 223 ms from: viazi-vidogo irreversible: 46498092 (-8) 2727213ms th_a application.cpp:460 handle_block ] Got block: #46498101 time: 2022-01-13T16:45:27 latency: 213 ms from: miss-jana irreversible: 46498093 (-8) ``` A different witness(AWS VM) didn't have this exception in the logs at the same time. The effect of the above exception is not known ``` 2670042ms th_a application.cpp:460 handle_block ] Got block: #46498084 time: 2022-01-13T16:44:30 latency: 42 ms from: miss-jana irreversible: 46498075 (-9) 2673043ms th_a application.cpp:460 handle_block ] Got block: #46498085 time: 2022-01-13T16:44:33 latency: 43 ms from: robert-hedler irreversible: 46498076 (-9) 2679172ms th_a application.cpp:460 handle_block ] Got block: #46498086 time: 2022-01-13T16:44:39 latency: 172 ms from: jogersenjo1 irreversible: 46498076 (-10) 2682077ms th_a application.cpp:460 handle_block ] Got block: #46498087 time: 2022-01-13T16:44:42 latency: 77 ms from: viazi-vidogo irreversible: 46498079 (-8) 2685165ms th_a application.cpp:460 handle_block ] Got block: #46498088 time: 2022-01-13T16:44:45 latency: 165 ms from: eifos-witness irreversible: 46498080 (-8) 2688131ms th_a application.cpp:460 handle_block ] Got block: #46498089 time: 2022-01-13T16:44:48 latency: 131 ms from: houdini-witness irreversible: 46498081 (-8) 2690804ms th_a application.cpp:509 handle_transaction ] Got 7 transactions from network 2691134ms th_a application.cpp:460 handle_block ] Got block: #46498090 time: 2022-01-13T16:44:51 latency: 134 ms from: viazi-vidogo irreversible: 46498082 (-8) 2694044ms th_a application.cpp:460 handle_block ] Got block: #46498091 time: 2022-01-13T16:44:54 latency: 44 ms from: robert-hedler irreversible: 46498082 (-9) 2697042ms th_a application.cpp:460 handle_block ] Got block: #46498092 time: 2022-01-13T16:44:57 latency: 42 ms from: wit-super irreversible: 46498082 (-10) 2700131ms th_a application.cpp:460 handle_block ] Got block: #46498093 time: 2022-01-13T16:45:00 latency: 131 ms from: houdini-witness irreversible: 46498083 (-10) 2706043ms th_a application.cpp:460 handle_block ] Got block: #46498094 time: 2022-01-13T16:45:06 latency: 43 ms from: miss-jana irreversible: 46498083 (-11) 2709043ms th_a application.cpp:460 handle_block ] Got block: #46498095 time: 2022-01-13T16:45:09 latency: 43 ms from: init0 irreversible: 46498083 (-12) 2712039ms th_a application.cpp:460 handle_block ] Got block: #46498096 time: 2022-01-13T16:45:12 latency: 39 ms from: hiltos-witness irreversible: 46498086 (-10) 2715049ms th_a application.cpp:460 handle_block ] Got block: #46498097 time: 2022-01-13T16:45:15 latency: 49 ms from: salah8kassab irreversible: 46498088 (-9) 2718168ms th_a application.cpp:460 handle_block ] Got block: #46498098 time: 2022-01-13T16:45:18 latency: 168 ms from: eifos-witness irreversible: 46498090 (-8) 2721172ms th_a application.cpp:460 handle_block ] Got block: #46498099 time: 2022-01-13T16:45:21 latency: 172 ms from: jogersenjo1 irreversible: 46498091 (-8) 2724078ms th_a application.cpp:460 handle_block ] Got block: #46498100 time: 2022-01-13T16:45:24 latency: 78 ms from: viazi-vidogo irreversible: 46498092 (-8) 2727043ms th_a application.cpp:460 handle_block ] Got block: #46498101 time: 2022-01-13T16:45:27 latency: 43 ms from: miss-jana irreversible: 46498093 (-8) ```

prandnum commented

2022-01-13 17:05:16 +00:00

(Migrated from gitlab.com)

assigned to @serkixenos

prandnum commented

2022-01-13 17:05:32 +00:00

(Migrated from gitlab.com)

@bobinson @serkixenos

CC: @hbelakon

@bobinson @serkixenos CC: @hbelakon

serkixenos commented

2022-01-20 14:38:21 +00:00

(Migrated from gitlab.com)

assigned to @vampik

serkixenos commented

2022-01-20 14:38:28 +00:00

(Migrated from gitlab.com)

unassigned @serkixenos

vampik commented

2022-01-21 12:26:49 +00:00

(Migrated from gitlab.com)

For additional information, I think we can add additional catch blocks in GRAPHENE_TRY_NOTIFY macros for:

const boost::exception&
const std::exception&

#define GRAPHENE_TRY_NOTIFY( signal, ... )                                    \
   try                                                                        \
   {                                                                          \
      signal( VA_ARGS );                                                      \
   }                                                                          \
   catch( const graphene::chain::plugin_exception& e )                        \
   {                                                                          \
      elog( "Caught plugin exception: ${e}", ("e", e.to_detail_string() ) );  \
      throw;                                                                  \
   }                                                                          \
   catch( ... )                                                               \
   {                                                                          \
      wlog( "Caught unexpected exception in plugin" );                        \
   }

For additional information, I think we can add additional catch blocks in GRAPHENE_TRY_NOTIFY macros for: ``` const boost::exception& const std::exception& ``` ``` #define GRAPHENE_TRY_NOTIFY( signal, ... ) \ try \ { \ signal( VA_ARGS ); \ } \ catch( const graphene::chain::plugin_exception& e ) \ { \ elog( "Caught plugin exception: ${e}", ("e", e.to_detail_string() ) ); \ throw; \ } \ catch( ... ) \ { \ wlog( "Caught unexpected exception in plugin" ); \ } ```

vampik commented

2022-01-21 12:33:50 +00:00

(Migrated from gitlab.com)

For better understanding what can cause this exception we need to understand which plugin throw it.

Now we can't tell which plugin throw this exception in applied_block signal.

I din't think up how we can tell what plugin throw when we use boost::signals2 (as it is done now). It can be done with custom commands map, for example.

For better understanding what can cause this exception we need to understand which plugin throw it. Now we can't tell which plugin throw this exception in `applied_block` signal. I din't think up how we can tell what plugin throw when we use `boost::signals2` (as it is done now). It can be done with custom commands map, for example.

vampik commented

2022-01-24 05:50:57 +00:00

(Migrated from gitlab.com)

changed time estimate to 18h

hbelakon commented

2022-01-28 04:32:52 +00:00

(Migrated from gitlab.com)

@vampik please assign to proper EPIC!

vampik commented

2022-01-28 09:44:59 +00:00

(Migrated from gitlab.com)

mentioned in commit 910362baf8

mentioned in commit 910362baf87db643da6b390b866d62ac6a57a2bd

vampik commented

2022-01-28 09:44:59 +00:00

(Migrated from gitlab.com)

mentioned in commit 43fbe98240

mentioned in commit 43fbe982408278c30deb3a2849550d33fcf44258

vampik commented

2022-01-28 09:47:29 +00:00

(Migrated from gitlab.com)

mentioned in merge request !56

vampik commented

2022-01-28 09:49:18 +00:00

(Migrated from gitlab.com)

Add additional try-catch blocks

serkixenos commented

2022-01-31 14:14:26 +00:00

(Migrated from gitlab.com)

mentioned in commit 66699f1e15

mentioned in commit 66699f1e15b59c39df6d5e529a7b84a01da97670

vampik commented

2022-01-31 14:14:26 +00:00

(Migrated from gitlab.com)

mentioned in commit 78fbf7c3cd

mentioned in commit 78fbf7c3cd02cfd4e374310b63c2b9c84a57e607

vampik commented

2022-01-31 14:24:15 +00:00

(Migrated from gitlab.com)

assigned to @prandnum

vampik commented

2022-01-31 14:24:33 +00:00

(Migrated from gitlab.com)

unassigned @vampik

vampik commented

2022-01-31 14:28:14 +00:00

(Migrated from gitlab.com)

@prandnum For now it is impossible to tell which plugin throw this exception.
Added some changes that would provide more detailed information to this situation.

The next step is to observe this error again, and get back to resolving once we have more complete context.

@prandnum For now it is impossible to tell which plugin throw this exception. Added some changes that would provide more detailed information to this situation. The next step is to observe this error again, and get back to resolving once we have more complete context.

vampik commented

2022-02-01 05:20:38 +00:00

(Migrated from gitlab.com)

assigned to @vampik

prandnum commented

2022-02-02 18:50:34 +00:00

(Migrated from gitlab.com)

@vampik what are the verification steps? merge the code into mainnet and run a mainnet witness_node and observer for errors?

CC: @serkixenos @bobinson @hbelakon

@vampik what are the verification steps? merge the code into mainnet and run a mainnet witness_node and observer for errors? CC: @serkixenos @bobinson @hbelakon

serkixenos commented

2022-02-02 19:24:39 +00:00

(Migrated from gitlab.com)

What was added to the code should enable us to get more precise debug info (stack trace) once the error pops up again. So, its not really a fix, its what we need to figure out a fix. Just let the node works for some time, and after day or two or three, lets look into logs and see if there is anything new for us there...

prandnum commented

2022-02-03 13:30:05 +00:00

(Migrated from gitlab.com)

ok. so the code is merged to the master branch so that I can run a mainnet witness node?

serkixenos commented

2022-02-03 20:04:25 +00:00

(Migrated from gitlab.com)

No, its not merged to master, but you can build develop branch for mainnet, and run it as a sync node.

prandnum commented

2022-02-28 17:15:15 +00:00

(Migrated from gitlab.com)

Ran a witness node for 7 days. Not able to reproduce the error. Closing the bug for now.

prandnum (Migrated from gitlab.com) closed this issue

2022-02-28 17:15:16 +00:00

exception seen in witness logs #245