BiblePay - TestNet Thread - Pool Testing for Proof of Bible Hash Pool (PoBh)

[happy_merchant]

I made a second account to test some stuff out. One thing that I noticed is that I seemed to get paid in full for doing very little work on block 773. According to my logs, I connected to the pool on happy_merchant_alt at 1:45:16. Block 773 took 55 minutes 5 seconds to mine. So, I worked on the block for roughly 10% of the block time, but I received credit as though I had worked on the entire block:

Code:

82624506-2b5f-436e-a5e1-bf6c4ee5101b	jc12345			773	19999.0000	8211.6667	8/11/2017 1:49:45 AM	27192.68	0.301980800376851	8/11/2017 1:49:45 AM	jc12345.1: 30898 (27193)
bd593ffa-497a-4b32-982c-19ef459d90ae	bible_pay		773	19999.0000	5367.8276	8/11/2017 1:49:45 AM	17775.39	0.301980800376851	8/11/2017 1:49:45 AM	lastleg: 27541 (17775)
beca7599-b7af-40fb-ba50-3ca1a7a23955	testbible		773	19999.0000	3773.2580	8/11/2017 1:49:45 AM	12495.03	0.301980800376851	8/11/2017 1:49:45 AM	testbible: 16941 (12495)
f9b00f4c-1515-43c5-861d-a05f5ca4db55	happy_merchant_alt	773	19999.0000	2646.2477	8/11/2017 1:49:45 AM	8762.97		0.301980800376851	8/11/2017 1:49:45 AM	happy_merchant_alt00: 12539 (8763)

45f169b3-51c1-4a0c-8f5c-ee8b09a1afd6	jc12345			772	19999.0000	6589.6708	8/11/2017 12:54:40 AM	24509.38	0.268863219343847	8/11/2017 12:54:40 AM	jc12345.1: 30855 (24509)
e5fa7538-29a6-40de-9818-51d12ba68463	bible_pay		772	19999.0000	6359.3726	8/11/2017 12:54:40 AM	23652.82	0.268863219343847	8/11/2017 12:54:40 AM	lastleg: 27602 (23653)
605dd1aa-8b70-4cee-905c-3e530b8f401b	testbible		772	19999.0000	4357.7661	8/11/2017 12:54:40 AM	16208.12	0.268863219343847	8/11/2017 12:54:40 AM	testbible: 16923 (16208)
d80c2584-34de-4df7-8ba0-94a1273df69a	happy_merchant		772	19999.0000	2692.1905	8/11/2017 12:54:40 AM	10013.23	0.268863219343847	8/11/2017 12:54:40 AM	happy_merchant00: 12911 (10013)

Code:

MINING_CREDIT	773	e35c1d44-0b03-4476-b9b8-34888baecc36	f9b00f4c-1515-43c5-861d-a05f5ca4db55	2646.2477	2646.2477	8/11/2017 1:49:45 AM

I had been working on block 773 on my original account at the same IP address up till then, so I don't know if that influenced somehow.

--edit--
Actually, looking at subsequent blocks, the HPS was a little lower so maybe mining time was taken into consideration for the calculation? Just didn't seem to make much difference in the payout. Realistically I doubt it's something that could be effectively abused in any case.

[1714058114]

1714058114

[1714058114]

1714058114

[1714058114]

1714058114

[1714058114]

1714058114

[bible_pay]

I made a second account to test some stuff out. One thing that I noticed is that I seemed to get paid in full for doing very little work on block 773. According to my logs, I connected to the pool on happy_merchant_alt at 1:45:16. Block 773 took 55 minutes 5 seconds to mine. So, I worked on the block for roughly 10% of the block time, but I received credit as though I had worked on the entire block:

Code:

82624506-2b5f-436e-a5e1-bf6c4ee5101b	jc12345			773	19999.0000	8211.6667	8/11/2017 1:49:45 AM	27192.68	0.301980800376851	8/11/2017 1:49:45 AM	jc12345.1: 30898 (27193)
bd593ffa-497a-4b32-982c-19ef459d90ae	bible_pay		773	19999.0000	5367.8276	8/11/2017 1:49:45 AM	17775.39	0.301980800376851	8/11/2017 1:49:45 AM	lastleg: 27541 (17775)
beca7599-b7af-40fb-ba50-3ca1a7a23955	testbible		773	19999.0000	3773.2580	8/11/2017 1:49:45 AM	12495.03	0.301980800376851	8/11/2017 1:49:45 AM	testbible: 16941 (12495)
f9b00f4c-1515-43c5-861d-a05f5ca4db55	happy_merchant_alt	773	19999.0000	2646.2477	8/11/2017 1:49:45 AM	8762.97		0.301980800376851	8/11/2017 1:49:45 AM	happy_merchant_alt00: 12539 (8763)

45f169b3-51c1-4a0c-8f5c-ee8b09a1afd6	jc12345			772	19999.0000	6589.6708	8/11/2017 12:54:40 AM	24509.38	0.268863219343847	8/11/2017 12:54:40 AM	jc12345.1: 30855 (24509)
e5fa7538-29a6-40de-9818-51d12ba68463	bible_pay		772	19999.0000	6359.3726	8/11/2017 12:54:40 AM	23652.82	0.268863219343847	8/11/2017 12:54:40 AM	lastleg: 27602 (23653)
605dd1aa-8b70-4cee-905c-3e530b8f401b	testbible		772	19999.0000	4357.7661	8/11/2017 12:54:40 AM	16208.12	0.268863219343847	8/11/2017 12:54:40 AM	testbible: 16923 (16208)
d80c2584-34de-4df7-8ba0-94a1273df69a	happy_merchant		772	19999.0000	2692.1905	8/11/2017 12:54:40 AM	10013.23	0.268863219343847	8/11/2017 12:54:40 AM	happy_merchant00: 12911 (10013)

Code:

MINING_CREDIT	773	e35c1d44-0b03-4476-b9b8-34888baecc36	f9b00f4c-1515-43c5-861d-a05f5ca4db55	2646.2477	2646.2477	8/11/2017 1:49:45 AM

I had been working on block 773 on my original account at the same IP address up till then, so I don't know if that influenced somehow.

--edit--
Actually, looking at subsequent blocks, the HPS was a little lower so maybe mining time was taken into consideration for the calculation? Just didn't seem to make much difference in the payout. Realistically I doubt it's something that could be effectively abused in any case.

Yeah, the current pool does try to take account HPS on miners that pool hop, but the synthetic HPS of the pool is not always accurate per block- but I think over time it would be a good average.  The payout for 773 was based on 8763 hash ps, but your _alt miner generally did about 10500 hash ps.  I wonder if you worked on at least 50% of the block or if you really got lucky.  I also wonder, how many threads are you running on this miner?

In any case, I am working on adding a share based system in, instead of the synthetic HPS reading to see if that works better, and Im trying to make it to where I can switch over to it but yet have both columns in all the reports.  Something like TotalShares and SharesSolved or something per row. 

Im still looking at the other posts with the logs you sent.

[bible_pay]

Alright, so my miner apparently dropped out of the pool for blocks 642-643 and 659-660. Here's the verbose debug log for blocks 658-661

https://pastebin.com/qdB4v9dX (block 658)
https://pastebin.com/G6kawJYc (block 659)
https://pastebin.com/qG5VSDf2 (block 660)
https://pastebin.com/npy6NbBB (block 661)

https://file.io/ODsv3P (entire log)

Nothing really jumps out at me from the logs. Doesn't look like other miners are having the same issue, so it's a little weird.

I took a look at the logs, and I believe the issue is on the pool side predominantly, but what happens occasionally, is the threads on the miner side get tied up with work that is too hard to solve for longer than the duration of the block, and 0 shares are submitted by the miner that count toward the block, even if the miner submitted the solution, the stats didnt update in time before the block was solved and paid. 

I think its probably more productive for us to test out the shares based payment and see if this results in a more frequent and accurate HPS reading and then we can re-test this again overnight.  Im going to try to work on the shares today.

[happy_merchant]

Yeah, the current pool does try to take account HPS on miners that pool hop, but the synthetic HPS of the pool is not always accurate per block- but I think over time it would be a good average.  The payout for 773 was based on 8763 hash ps, but your _alt miner generally did about 10500 hash ps.  I wonder if you worked on at least 50% of the block or if you really got lucky.  I also wonder, how many threads are you running on this miner?

Was only mining on happy_merchant_alt for less than 5 minutes out of the 55 minutes for that block, so it definitely wasn't 50%. Just running 1 thread on my pool miner.

I took a look at the logs, and I believe the issue is on the pool side predominantly, but what happens occasionally, is the threads on the miner side get tied up with work that is too hard to solve for longer than the duration of the block, and 0 shares are submitted by the miner that count toward the block, even if the miner submitted the solution, the stats didnt update in time before the block was solved and paid. 

I don't know if it's relevant, but it hasn't happened since I swapped pool accounts. It was happening pretty frequently before, but now it's been over 40 blocks without dropping any. The miner is identical, I just changed the worker_id. Also, I didn't notice it happening before I spammed all those withdrawal transactions, so I'm wondering if maybe something in that account got corrupted. Going to keep mining on my alt account for a while to verify that it's not happening, then I'll try swapping back again.

[bible_pay]

Yeah, the current pool does try to take account HPS on miners that pool hop, but the synthetic HPS of the pool is not always accurate per block- but I think over time it would be a good average.  The payout for 773 was based on 8763 hash ps, but your _alt miner generally did about 10500 hash ps.  I wonder if you worked on at least 50% of the block or if you really got lucky.  I also wonder, how many threads are you running on this miner?

Was only mining on happy_merchant_alt for less than 5 minutes out of the 55 minutes for that block, so it definitely wasn't 50%. Just running 1 thread on my pool miner.

I took a look at the logs, and I believe the issue is on the pool side predominantly, but what happens occasionally, is the threads on the miner side get tied up with work that is too hard to solve for longer than the duration of the block, and 0 shares are submitted by the miner that count toward the block, even if the miner submitted the solution, the stats didnt update in time before the block was solved and paid. 

I don't know if it's relevant, but it hasn't happened since I swapped pool accounts. It was happening pretty frequently before, but now it's been over 40 blocks without dropping any. The miner is identical, I just changed the worker_id. Also, I didn't notice it happening before I spammed all those withdrawal transactions, so I'm wondering if maybe something in that account got corrupted. Going to keep mining on my alt account for a while to verify that it's not happening, then I'll try swapping back again.

Oh ok, well I do know that the current version of the pool doesnt work as well with one thread (although I dont want to encourage a huge number of threads as that would saturate the pool) but anyway, with one thread, I can see falling out of the block, as if that one thread gets tied up with work it could miss a block.  Maybe try 4 threads or so? 

[happy_merchant]

Oh ok, well I do know that the current version of the pool doesnt work as well with one thread (although I dont want to encourage a huge number of threads as that would saturate the pool) but anyway, with one thread, I can see falling out of the block, as if that one thread gets tied up with work it could miss a block.  Maybe try 4 threads or so?  

Ah, I see, that actually could be the issue then. It did start happening around the time I swapped from 8 threads to 1 thread. I'll give that a shot.

--edit--
My alt account was dropping blocks too, so I bumped it up from 1 thread to 4 threads starting at block 912.

[tiras]

bible_pay ,   I realize can ignore this q, but can you give ETA for a live pool ?   is it a week , month or longer ?   

[happy_merchant]

Code:

1f60b28d-cd84-4a53-b9df-aa486e911660	Anonymous	925	19998.0000	36.1035		8/12/2017 2:24:18 AM	24674.53	0.00146318753300487	8/12/2017 2:24:18 AM	Anonymous
51becfe1-2bde-498c-b485-181c00f78081	bible_pay	925	19998.0000	28.7325		8/12/2017 2:24:18 AM	19636.9		0.00146318753300487	8/12/2017 2:24:18 AM	lastleg: 24382 (19637)
2e1d36d9-fe36-4bdf-b1c6-16eff6aae895	testbible	925	19998.0000	18.7215		8/12/2017 2:24:18 AM	12795.02	0.00146318753300487	8/12/2017 2:24:18 AM	testbible: 17191 (12795)
86c24031-52d0-4b0a-9ce9-47552a481be8	happy_merchant	925	19998.0000	19914.4426	8/12/2017 2:24:18 AM	13610314.54	0.00146318753300487	8/12/2017 2:24:18 AM	xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx: 9013 (13610315)

38d49a58-7f7f-4805-9719-29e829785535	Anonymous	924	19998.0000	36.1035		8/12/2017 2:24:18 AM	24674.53	0.00146318753300487	8/12/2017 2:24:18 AM	Anonymous
a0fa143e-9273-4e43-938e-e0af8de565b2	bible_pay	924	19998.0000	28.7325		8/12/2017 2:24:18 AM	19636.9		0.00146318753300487	8/12/2017 2:24:18 AM	lastleg: 24382 (19637)
0f0c56cd-daf2-4676-876c-f9f54e8bced4	testbible	924	19998.0000	18.7215		8/12/2017 2:24:18 AM	12795.02	0.00146318753300487	8/12/2017 2:24:18 AM	testbible: 17191 (12795)
817abd92-0d98-4027-b659-ebfe0a9c62b8	happy_merchant	924	19998.0000	19914.4426	8/12/2017 2:24:18 AM	13610314.54	0.00146318753300487	8/12/2017 2:24:18 AM	xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx: 9013 (13610315)

Alright, I'm not sure what's going on here, but I can assure you that hashrate is not correct. getmininginfo is reporting 9190 hashps.

It started reporting like that right after I created the miner named "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx xxxxxxxxxxxxxxxxxxxxx". That's 100 'x' characters, which looks like the cap on worker names.

--edit--
Possibly related, this is being reported on the account page for the worker id:

Code:

Username:	xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx	Threads:	32762	HPS:	10609.6932326281

The thread count is clearly off, it's running at 4 threads.

--edit--
The miner also seems to be dropping a large amount of blocks. It didn't register at all for blocks 931-936.

It is getting credited the disproportionate share of the reward for the blocks where it does get recorded, though.

--edit--
I swapped to an alternate account and created a worker id "yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy yyyyyyyyyyyyyyyyyyyyy", but I wasn't able to reproduced what happened above. It functioned normally.

--edit--
Created another worker id with 100 'z's on my original account and it had the same issue as 'xxx...'. Weird. I see someone's cleaning up the mess though so you probably already noticed it.

--edit--
Now my happy_merchant00 worker id looks like it's doing it. Maybe it wasn't related to the long worker names. I tried entering some unicode gibberish worker ids and they all seemed to get converted ASCII letters and question marks so I figured they were being handled okay, but maybe they caused a problem. Also some punctuation-only ids including just spaces.

[happy_merchant]

Another weird thing that I've been wondering for a while now. The network_khashps reported by getmininginfo seems to be off. Right now for example it's saying 465 kh/s. Adding the values from the pool, it should be around 60-70 kh/s. It's possible there's a miner or two on the test chain who aren't in the pool, but it's definitely not 400 kh/s worth of non-pool miners since the pool is finding every block.

[happy_merchant]

Also, there were a couple times tonight that logging in to the pool website failed. No errors or anything, you just click login and the page reloads but you're not logged in. It's currently happening at 5:11 AM PST.

[bible_pay]

Also, there were a couple times tonight that logging in to the pool website failed. No errors or anything, you just click login and the page reloads but you're not logged in. It's currently happening at 5:11 AM PST.

Oh my another morning of IT issues!  Thanks for all the help btw.
So, on the long miner name itself, I added a length restriction of 19 chars to the page and deleted your worker, so please recreate it.
I dont know why the hashPS join subsystem was calculating your hashes wrong.  Im still tweaking the shares anyway, so its moot to even fix that.  Let me try to get that working so we can test that new system. 
The pool backfilled the block_distribution back in automatically without your worker, but after you recreate it you should be back on, but yes, if this happened in prod, I would need a procedure to back out the money also from the users, and in testnet you still got credited.

Regarding the inability to log in, by the time I woke up, the system was back up. Ill look at the logs.  Something is causing the microsoft app pool to crash, and then when the 'down' elapse period is exceeded, it brings itself back up.  I assume mining is still occurring at that time.

[bible_pay]

Another weird thing that I've been wondering for a while now. The network_khashps reported by getmininginfo seems to be off. Right now for example it's saying 465 kh/s. Adding the values from the pool, it should be around 60-70 kh/s. It's possible there's a miner or two on the test chain who aren't in the pool, but it's definitely not 400 kh/s worth of non-pool miners since the pool is finding every block.

Yeah, I see our 4 miners overnight were doing about lets say 80khps, and the getmininginfo for the network shows 440khps right now, and I agree probably only 1-2 stragglers out there solo mining max, that would bring it to 100khps.

Let me audit the c++ code now and Ill get back to you.

[happy_merchant]

The pool backfilled the block_distribution back in automatically without your worker, but after you recreate it you should be back on, but yes, if this happened in prod, I would need a procedure to back out the money also from the users, and in testnet you still got credited.

Yeah, that's definitely a benefit of having an immature balance system. If a bug popped up or someone blatantly tried to exploit on live, there'd be time to revoke their credit and redistribute the reward before they pulled it out of the pool.

[jc12345]

Withdrawal and anonymous works fine. Hash rate is close enough.

[bible_pay]

Another weird thing that I've been wondering for a while now. The network_khashps reported by getmininginfo seems to be off. Right now for example it's saying 465 kh/s. Adding the values from the pool, it should be around 60-70 kh/s. It's possible there's a miner or two on the test chain who aren't in the pool, but it's definitely not 400 kh/s worth of non-pool miners since the pool is finding every block.

Yeah, I see our 4 miners overnight were doing about lets say 80khps, and the getmininginfo for the network shows 440khps right now, and I agree probably only 1-2 stragglers out there solo mining max, that would bring it to 100khps.

Let me audit the c++ code now and Ill get back to you.

So looking at the networkhashps calculations, it appears the underlying chain work is accurate in each block, and the calculation model itself, that averages the networkKhasPs over time looks solid.  The issue comes into play where there are two versions of the function that regresses back to the last diff change.  One version appears to have the parameters passed in backwards, (not by me, just by the unusual parameter we have set up in the consensus which by themselves are correct for DGW but dont translate to BTC) and the other, well it looks like the defaults calculate something entirely wrong, so either way we need a code change.  So anyway, I ended up doing some calculations and found generally, what works pretty good is our BLOCKS_PER_DAY divided by 24 hours (that means we would see the NetworkKhashPs over the last hour).  You can simulate this by doing a getnetworkhashps 960 951 and now we end up with a 31khps, which seems right.  I went back through the chain when I was solo mining, for example getnetworkhashps 50 40, and you can see it drop to .01 etc, so this appears to be correct now.  I am modifying the code so this will be in the next release.

Thanks.

[happy_merchant]

Whew, 72 MH/s. Yeah, it's looking like all workers on the happy_merchant account are bugged now.

I'll swap over to an alt account until the shares system is updated.

[ArkMage]

I see a lot of progress here. Any ETA for pool mainnet launch date?

[bible_pay]

I see a lot of progress here. Any ETA for pool mainnet launch date?

Will update a little more in an hour but from a very high perspective, today was a great day, deploys getting made now so we can test again with the shares system.  I believe we had a bug on the pool side.

Im just guessing but I think within a few more days, we might be able to test out prod.

We must test the windows client against the pool now.

Happy, I just released a new version of the pool, this has the shares calculation showing up in "Leaderboard".

[bible_pay]

Whew, 72 MH/s. Yeah, it's looking like all workers on the happy_merchant account are bugged now.

I'll swap over to an alt account until the shares system is updated.

Oh really?  Could you give me more info, is this still happening now that the new version of the pool is deployed, and if so what block # got paid too much?

[happy_merchant]

Oh really?  Could you give me more info, is this still happening now that the new version of the pool is deployed, and if so what block # got paid too much?

Code:

91c85007-5adf-4447-8c03-8d5a9355cd19	Anonymous	965	19999.0000	6.4608		8/12/2017 9:59:03 AM	23600.76	0.000273753441763739	8/12/2017 9:59:03 AM	Anonymous
835c5ac2-fff8-4908-8880-0dd189e8dd0b	bible_pay	965	19999.0000	6.8437		8/12/2017 9:59:03 AM	24999.68	0.000273753441763739	8/12/2017 9:59:03 AM	lastleg: 32246 (25000)
fc358f22-9ae0-4c4d-928b-724f399b2a7e	testbible	965	19999.0000	3.4687		8/12/2017 9:59:03 AM	12670.99	0.000273753441763739	8/12/2017 9:59:03 AM	testbible: 17256 (12671)
36b54a51-03b0-432c-86cb-f4f1b3aeca0e	happy_merchant	965	19999.0000	19982.2267	8/12/2017 9:59:03 AM	72993517.84	0.000273753441763739	8/12/2017 9:59:03 AM	happy_merchant00: 28352 (72993518)

Not sure when deployment happened, but this was after changing the worker name character limit.

--edit--
Looks like that worker was also counted for block 966 but the HPS was reported correctly there. Might've been just before you updated.

Code:

d55a9e75-f1c7-4ad6-bea6-1765c9452866	Anonymous		966	19999.0000	4883.8682	8/12/2017 10:14:52 AM	23735.55	0.205761771699916	8/12/2017 10:14:52 AM	Anonymous
23528b46-c381-4318-9511-e405860c7a4a	bible_pay		966	19999.0000	4703.9429	8/12/2017 10:14:52 AM	22861.11	0.205761771699916	8/12/2017 10:14:52 AM	lastleg: 32434 (22861)
abcfc4ab-62a0-4773-94e2-0b67fc40daa9	testbible		966	19999.0000	4102.4177	8/12/2017 10:14:52 AM	19937.71	0.205761771699916	8/12/2017 10:14:52 AM	testbible: 17258 (19938)
938a3deb-1f88-408d-8b77-b717a4b920c0	happy_merchant_alt2	966	19999.0000	2881.6733	8/12/2017 10:14:52 AM	14004.9		0.205761771699916	8/12/2017 10:14:52 AM	happy_worker: 18680 (14005)
1a0a25a3-9aba-493b-bffe-cd82534446bf	happy_merchant		966	19999.0000	3427.0979	8/12/2017 10:14:52 AM	16655.66	0.205761771699916	8/12/2017 10:14:52 AM	happy_merchant00: 24314 (16656)

Also looks like I got about a 50% extra payout for block 966 by swapping accounts midway. Will check if that happens in block 979 too since I just swapped accounts again.