How the sausage is made: diving into Podping on Hive

avatar

I'll try to give a broadly understandable explanation up front, but at the end I'm going to be posting for the Hive Devs and particularly for the "dude's named Ben" (that's a @no-agenda thing) who run Hive's absolutely crucial API servers (also called RPCs or Nodes).

image.png

You can see all of them if you run the PeakD Nodes diagnostic tool. These are the magic boxes which make accessing a slow blockchain like accessing a fast database but whilst performing the magic trick of all staying synchronised and decentralised.

When you run an application like @podping, which writes a transaction to the chain every few seconds, sometimes 4 or 5 per minute, you test these API servers pretty heavily.

The first version of Podping we launched ran flawlessly for over a month. A pretty staggering achievement. When it did go wrong (which I wrote about here) I wasn't sure why.

Since then I've done a huge amount more testing and the actual Hive-Writer program has been completely re-written. But I am able to replicate the specific way in which it failed the other week.

But, and this is something you come to understand when developing based on an open system, run by multiple different people with varying hardware and software set ups, not everything is identical.

So after quite a lot of work I arrive at a diagnostic screen that looks like this for a node that is working perfectly. A new node is selected, in this case [https://hive.roelandp.nl] @roelandp's node, and the program starts sending notifications through it. The first one takes 1.12s to send but from then on the time is roughly half that. I suspect some sort of caching of the sending user's details is going on.

2021-06-22 16:17:43,772 INFO root MainThread : New Hive Nodes in use: <Hive node=https://hive.roelandp.nl, nobroadcast=False>
2021-06-22 16:17:44,274 INFO root MainThread : Transaction sent: 4bb38edc3a2c527b8b84464908eebaa15f57b76f - Num urls: 9 - Size of Urls: 414 - Json size: 491
2021-06-22 16:17:44,275 INFO root MainThread : Task time: 1.12 - Queue size: 0
2021-06-22 16:18:05,132 INFO root MainThread : Transaction sent: 60950ec21454af61151d08d6de667a1eee25c8ec - Num urls: 9 - Size of Urls: 379 - Json size: 456
2021-06-22 16:18:05,133 INFO root MainThread : Task time: 0.62 - Queue size: 0
2021-06-22 16:18:08,744 INFO root MainThread : Transaction sent: 45ef53818dc2a02b99be44f3046525f1f791e41e - Num urls: 10 - Size of Urls: 394 - Json size: 476
2021-06-22 16:18:08,745 INFO root MainThread : Task time: 0.59 - Queue size: 0
2021-06-22 16:18:12,406 INFO root MainThread : Transaction sent: c86f9ddf863d0060e328a930268900a6f6ce62d2 - Num urls: 10 - Size of Urls: 399 - Json size: 481
2021-06-22 16:18:12,407 INFO root MainThread : Task time: 0.63 - Queue size: 0
2021-06-22 16:18:15,964 INFO root MainThread : Transaction sent: 45e41d4b43a099a727a6112167bb4af8442f8ac0 - Num urls: 10 - Size of Urls: 397 - Json size: 479
2021-06-22 16:18:15,965 INFO root MainThread : Task time: 0.53 - Queue size: 0
2021-06-22 16:18:19,498 INFO root MainThread : Transaction sent: 6a827ffc5214f8f98139c80b91d08a4eea058728 - Num urls: 10 - Size of Urls: 393 - Json size: 475
2021-06-22 16:18:19,499 INFO root MainThread : Task time: 0.51 - Queue size: 0
2021-06-22 16:18:41,348 INFO root MainThread : Transaction sent: a0ea5d5458ae20c496f37c423717846b2c5b5091 - Num urls: 10 - Size of Urls: 396 - Json size: 478
2021-06-22 16:18:41,349 INFO root MainThread : Task time: 0.58 - Queue size: 0
2021-06-22 16:18:45,012 INFO root MainThread : Transaction sent: a201707ce896af08010f2206bdfc0078939b201b - Num urls: 10 - Size of Urls: 396 - Json size: 478
2021-06-22 16:18:45,013 INFO root MainThread : Task time: 0.64 - Queue size: 0
2021-06-22 16:18:48,544 INFO root MainThread : Transaction sent: 21da7dd55a723f96950168f7985d9340d9623fe0 - Num urls: 10 - Size of Urls: 398 - Json size: 480
2021-06-22 16:18:48,546 INFO root MainThread : Task time: 0.51 - Queue size: 0
2021-06-22 16:18:52,190 INFO root MainThread : Transaction sent: 2a151e2c67d0a71a179872b34b4b3f30f9581019 - Num urls: 10 - Size of Urls: 399 - Json size: 481
2021-06-22 16:18:52,191 INFO root MainThread : Task time: 0.62 - Queue size: 0
2021-06-22 16:18:55,810 INFO root MainThread : Transaction sent: 5f451eb8b23023161d6460837151e8a69e691b3b - Num urls: 10 - Size of Urls: 395 - Json size: 477
2021-06-22 16:18:55,811 INFO root MainThread : Task time: 0.59 - Queue size: 0
2021-06-22 16:19:17,439 INFO root MainThread : Transaction sent: 37c7d366e15e1e66a6187250e071253d282f9dfb - Num urls: 10 - Size of Urls: 398 - Json size: 480
2021-06-22 16:19:17,440 INFO root MainThread : Task time: 0.53 - Queue size: 0
2021-06-22 16:19:20,961 INFO root MainThread : Transaction sent: 607a2cc907c5a8f5a8d1410919aed06c7883104d - Num urls: 10 - Size of Urls: 388 - Json size: 470
2021-06-22 16:19:20,962 INFO root MainThread : Task time: 0.50 - Queue size: 0
2021-06-22 16:19:42,629 INFO root MainThread : Transaction sent: a0feb193c5940a90e0e7837743f66e95719a8a91 - Num urls: 8 - Size of Urls: 326 - Json size: 399
2021-06-22 16:19:42,630 INFO root MainThread : Task time: 0.52 - Queue size: 0
2021-06-22 16:20:04,172 INFO root MainThread : Transaction sent: 02dd4625f2d87e6123d0d1a360a8e5f1b8c82927 - Num urls: 5 - Size of Urls: 202 - Json size: 263
2021-06-22 16:20:04,173 INFO root MainThread : Task time: 0.53 - Queue size: 0
2021-06-22 16:20:23,091 INFO root MainThread : Transaction sent: b35a6413aff526c50a299de720f66e4d385e7679 - Num urls: 5 - Size of Urls: 230 - Json size: 291
2021-06-22 16:20:23,092 INFO root MainThread : Task time: 0.51 - Queue size: 0

By comparison, when I switch to the nodes that appear below, I can send files, but I get trouble, specifically this missing required posting authority:Missing Posting Authority podping.bol occurred: <class 'beemapi.exceptions.UnhandledRPCError'> error. When I retry, almost without exception, it works. But I have no idea why it doesn't work first time.

2021-06-22 16:38:28,387 WARNING root MainThread : Node in use: <Hive node=https://rpc.ausbit.dev, nobroadcast=False>
2021-06-22 16:38:28,388 ERROR root MainThread : missing required posting authority:Missing Posting Authority podping.bol occurred: <class 'beemapi.exceptions.UnhandledRPCError'>
2021-06-22 16:38:28,936 INFO root MainThread : New Hive Nodes in use: <Hive node=https://api.pharesim.me, nobroadcast=False>
2021-06-22 16:38:28,936 WARNING root MainThread : <Hive node=https://api.pharesim.me, nobroadcast=False>
2021-06-22 16:38:28,937 ERROR root MainThread : Waiting 1s
2021-06-22 16:38:29,939 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 6 - <Hive node=https://api.pharesim.me, nobroadcast=False>
2021-06-22 16:38:30,430 INFO root MainThread : Transaction sent: 0b8b8203cd798c870e9be2541affcc5b53ba7799 - Num urls: 6 - Size of Urls: 252 - Json size: 317
2021-06-22 16:38:30,431 INFO root MainThread : Overhead: 65
2021-06-22 16:38:30,431 WARNING root MainThread : ----> FAILURE CLEARED after 1 retries - <Hive node=https://api.pharesim.me, nobroadcast=False> <-----

What's interesting above is that even though @pharesim's node does sometimes give me trouble: it is the node which posted the example above on the line FAILURE CLEARED. So this isn't a black and white failure.

Below is a grep -E "FAILURE COUNT|override|time|New|Transaction" of the output which just focuses on the failing nodes.

So my next step is to talk to @arcange @ausbitbank @ecency @blocktrades @anyx @deathwing @pharesim and see if we can figure out either what's strange in my code (definitely a possibility), what's not working on the Beem Python library (which I'm using) or something in the way their API Nodes are configured.

2021-06-22 16:24:10,860 INFO root MainThread : New Hive Nodes in use: <Hive node=https://hive-api.arcange.eu, nobroadcast=False>
2021-06-22 16:24:11,864 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 6 - <Hive node=https://hive-api.arcange.eu, nobroadcast=False>
2021-06-22 16:24:13,163 INFO root MainThread : New Hive Nodes in use: <Hive node=https://rpc.ecency.com, nobroadcast=False>
2021-06-22 16:24:14,169 INFO root MainThread : FAILURE COUNT: 2 - RETRYING num_urls: 6 - <Hive node=https://rpc.ecency.com, nobroadcast=False>
2021-06-22 16:24:15,091 INFO root MainThread : Transaction sent: dd4c8c0398ee754e1a02d65b3dce4e3ba78ee12b - Num urls: 6 - Size of Urls: 294 - Json size: 359
2021-06-22 16:24:15,093 INFO root MainThread : Task time: 5.64 - Queue size: 0
2021-06-22 16:24:32,300 INFO root MainThread : New Hive Nodes in use: <Hive node=https://api.hive.blog, nobroadcast=False>
2021-06-22 16:24:33,303 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 7 - <Hive node=https://api.hive.blog, nobroadcast=False>
2021-06-22 16:24:34,221 INFO root MainThread : Transaction sent: e77c3b95b5e130ab5f8699b1ffca9c6bab9e004b - Num urls: 7 - Size of Urls: 278 - Json size: 347
2021-06-22 16:24:34,222 INFO root MainThread : Task time: 3.46 - Queue size: 0
2021-06-22 16:24:54,134 INFO root MainThread : New Hive Nodes in use: <Hive node=https://api.openhive.network, nobroadcast=False>
2021-06-22 16:24:55,138 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 4 - <Hive node=https://api.openhive.network, nobroadcast=False>
2021-06-22 16:24:56,158 INFO root MainThread : Transaction sent: ea355dacd8a8921d4d3c69f608e937078efecff6 - Num urls: 4 - Size of Urls: 157 - Json size: 214
2021-06-22 16:24:56,160 INFO root MainThread : Task time: 3.59 - Queue size: 0
2021-06-22 16:25:15,410 INFO root MainThread : New Hive Nodes in use: <Hive node=https://api.ha.deathwing.me, nobroadcast=False>
2021-06-22 16:25:16,412 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 6 - <Hive node=https://api.ha.deathwing.me, nobroadcast=False>
2021-06-22 16:25:17,298 INFO root MainThread : Transaction sent: 62e6d601402d983632b59eda85d6993cb460889c - Num urls: 6 - Size of Urls: 236 - Json size: 301
2021-06-22 16:25:17,299 INFO root MainThread : Task time: 3.40 - Queue size: 0
2021-06-22 16:25:36,955 INFO root MainThread : New Hive Nodes in use: <Hive node=https://anyx.io, nobroadcast=False>
2021-06-22 16:25:37,959 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 6 - <Hive node=https://anyx.io, nobroadcast=False>
2021-06-22 16:25:38,799 INFO root MainThread : Transaction sent: 913fcae36b4c8c16705bb0960267a4d9cb23317c - Num urls: 6 - Size of Urls: 253 - Json size: 318
2021-06-22 16:25:38,801 INFO root MainThread : Task time: 3.49 - Queue size: 0
2021-06-22 16:25:57,979 INFO root MainThread : New Hive Nodes in use: <Hive node=https://api.deathwing.me, nobroadcast=False>
2021-06-22 16:25:58,981 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 6 - <Hive node=https://api.deathwing.me, nobroadcast=False>
2021-06-22 16:25:59,504 INFO root MainThread : Transaction sent: b7348e57bc03ebd1e6352a8e16d6e91d8e0130f4 - Num urls: 6 - Size of Urls: 265 - Json size: 330
2021-06-22 16:25:59,506 INFO root MainThread : Task time: 2.56 - Queue size: 0
2021-06-22 16:26:23,284 INFO root MainThread : New Hive Nodes in use: <Hive node=https://api.pharesim.me, nobroadcast=False>
2021-06-22 16:26:24,287 INFO root MainThread : FAILURE COUNT: 1 - RETRYING num_urls: 7 - <Hive node=https://api.pharesim.me, nobroadcast=False>
2021-06-22 16:26:24,778 INFO root MainThread : Transaction sent: d196747493c4f37139c8acb6e04fc4be243de937 - Num urls: 7 - Size of Urls: 299 - Json size: 368
2021-06-22 16:26:24,779 INFO root MainThread : Task time: 2.70 - Queue size: 0

brianoflondon hive footer.png



0
0
0.000
6 comments
avatar

Fantastic explanation. Thanks for sharing.

0
0
0.000
avatar
(Edited)

Well, I started to see the "missing posting authority" error when voting on posts today so I think there is something else going on.

Edit, I got the error again while broadcasting this replay.

0
0
0.000
avatar

Congratulations @brianoflondon! You have completed the following achievement on the Hive blockchain and have been rewarded with new badge(s) :

You distributed more than 63000 upvotes.
Your next target is to reach 64000 upvotes.

You can view your badges on your board and compare yourself to others in the Ranking
If you no longer want to receive notifications, reply to this comment with the word STOP

0
0
0.000