BScrk / zecproxy

Stratum proxy for Zcash
52 stars 34 forks source link

Zecproxy crashes #4

Closed tax79 closed 6 years ago

tax79 commented 7 years ago

Hello. Sometimes I get the following error and zecproxy crashes:

2017/10/25 01:40:03 INFO # Pool closed the connection...
2017/10/25 01:40:03 ERROR # Waiting 10 seconds before attempting to restart the Stratum Proxy
2017/10/25 01:40:07 INFO # Submit work for M1
2017/10/25 01:40:07 ERROR # Network error, Error: This socket has been ended by the other party
2017/10/25 01:40:07 INFO # Connecting to zec-eu2.nanopool.org:6666
2017/10/25 01:40:07 INFO # Connected to pool zec-eu2.nanopool.org:6666
2017/10/25 01:40:07 WARN # Resetting workers...
2017/10/25 01:40:07 INFO # Subscribing to pool...
2017/10/25 01:40:07 INFO # Stratum session id 133b00000000000012ad3f9336937471
2017/10/25 01:40:07 INFO # Authorizing mining wallet t1Qrz2NubDZ2GmsfC2.............................
2017/10/25 01:40:07 INFO # New target : 00028f5c00000000000000000000000000000000000000000000000000000000
2017/10/25 01:40:07 INFO # Mining wallet t1Qrz2NubDZ2GmsfC2............................. authorization granted
2017/10/25 01:40:07 INFO # New work : f0c6102e64d3175a22546a9d5d83a9d338c4477d9bdb16c46a315ebf16884145
2017/10/25 01:40:07 WARN # peer M4 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M4 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M3 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M3 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M3 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M3 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M3 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M3 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M1 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M1 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M1 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M1 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M1 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:07 WARN # peer M1 disconnected
2017/10/25 01:40:07 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:09 WARN # peer M2 disconnected
2017/10/25 01:40:09 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:09 WARN # peer M2 disconnected
2017/10/25 01:40:09 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:09 WARN # peer M2 disconnected
2017/10/25 01:40:09 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:09 WARN # peer M2 disconnected
2017/10/25 01:40:09 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:09 WARN # peer M2 disconnected
2017/10/25 01:40:09 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:09 WARN # peer M2 disconnected
2017/10/25 01:40:09 INFO # 0 peer(s) mining on this proxy
2017/10/25 01:40:13 WARN # ZEC STRATUM PROXY RESTARTING...
2017/10/25 01:40:13 INFO # ZEC STRATUM PROXY STARTING...
2017/10/25 01:40:13 INFO # Connecting to zec-eu1.nanopool.org:6666
2017/10/25 01:40:13 INFO # Connected to pool zec-eu1.nanopool.org:6666
2017/10/25 01:40:13 INFO # Subscribing to pool...
2017/10/25 01:40:13 INFO # Stratum session id db010000000000002d2ed6f2e68c0f4c
2017/10/25 01:40:13 INFO # Authorizing mining wallet t1Qrz2NubDZ2GmsfC2.............................
2017/10/25 01:40:13 INFO # New target : 00028f5c00000000000000000000000000000000000000000000000000000000
2017/10/25 01:40:14 INFO # Mining wallet t1Qrz2NubDZ2GmsfC2............................. authorization granted
2017/10/25 01:40:14 INFO # New work : f0c6102e64d3175a22546a9d5d83a9d338c4477d9bdb16c46a315ebf16884145
/home/tax79/zecproxy/lib/pool_connector.js:85
                this.miners.broadcastToMiners(obj);
                            ^

TypeError: Cannot read property 'broadcastToMiners' of null
    at PoolConnector.onData (/home/tax79/zecproxy/lib/pool_connector.js:85:29)
    at DestroyableTransform.poolSocket.on.pipe.on (/home/tax79/zecproxy/lib/pool_connector.js:158:43)
    at emitOne (events.js:115:13)
    at DestroyableTransform.emit (events.js:210:7)
    at addChunk (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:284:12)
    at readableAddChunk (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:271:11)
    at DestroyableTransform.Readable.push (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:238:10)
    at DestroyableTransform.Transform.push (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_transform.js:146:32)
    at push (/home/tax79/zecproxy/node_modules/ndjson/node_modules/split2/index.js:52:10)
    at DestroyableTransform.transform [as _transform] (/home/tax79/zecproxy/node_modules/ndjson/node_modules/split2/index.js:33:5)
BScrk commented 7 years ago

Thanks for the report. Will fix this issue asap

digitalshamansky commented 6 years ago

Almost the same issue here

/home/shaman/zecproxy/lib/pool_connector.js:94 this.miners.sendToMiner(obj.id, obj); ^

TypeError: Cannot read property 'sendToMiner' of null at onData (/home/shaman/zecproxy/lib/pool_connector.js:94:28) at DestroyableTransform. (/home/shaman/zecproxy/lib/pool_connector.js:158:43) at emitOne (events.js:77:13) at DestroyableTransform.emit (events.js:169:7) at addChunk (/home/shaman/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:284:12) at readableAddChunk (/home/shaman/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:271:11) at DestroyableTransform.Readable.push (/home/shaman/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:238:10) at DestroyableTransform.Transform.push (/home/shaman/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_transform.js:146:32) at push (/home/shaman/zecproxy/node_modules/ndjson/node_modules/split2/index.js:52:10) at DestroyableTransform.transform [as _transform] (/home/shaman/zecproxy/node_modules/ndjson/node_modules/split2/index.js:33:5) at DestroyableTransform.Transform._read (/home/shaman/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_transform.js:182:10) at DestroyableTransform.Transform._write (/home/shaman/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_transform.js:170:83) at doWrite (/home/shaman/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_writable.js:406:64)

BScrk commented 6 years ago

@tax79 are you sure you are using 1.0.5 version ? This issue was fixed in this .5 version...

BScrk commented 6 years ago

@digitalshamansky not exactly same issue, can you please send me the full logfile ?

tax79 commented 6 years ago

@BScrk

$ cat zecproxy/package.json 
{
  "name": "zecproxy",
  "version": "1.0.5",
  "description": "Zcash Stratum Proxy",
  "main": "proxy.js",
  "scripts": {},
  "dependencies": {
    "chalk": "^2.1.0",
    "date-and-time": "^0.5.0",
    "ldjson-stream": "^1.2.1",
    "ndjson": "^1.5.0"
  }
}
digitalshamansky commented 6 years ago

@BScrk unfortunately it's all what I have now, zecproxy was running about 5 days, and this night has crashed. Now I've launched it with debug and logging to file.

{ "name": "zecproxy", "version": "1.0.5", "description": "Zcash Stratum Proxy", "main": "proxy.js", "scripts": {}, "dependencies": { "chalk": "^2.1.0", "date-and-time": "^0.5.0", "ldjson-stream": "^1.2.1", "ndjson": "^1.5.0" } }

tax79 commented 6 years ago

@BScrk It happens not very often. I have written a script that logs and restarts automatically the program. Logs of today's crash for example:

2017/10/30 05:45:00 INFO # Submit work for M1
2017/10/30 05:45:00 INFO # Work from M1 accepted
2017/10/30 05:45:01 INFO # Pool closed the connection...
2017/10/30 05:45:01 ERROR # Waiting 10 seconds before attempting to restart the Stratum Proxy
2017/10/30 05:45:02 INFO # Submit work for M3
2017/10/30 05:45:02 ERROR # Network error, Error: This socket has been ended by the other party
2017/10/30 05:45:02 INFO # Connecting to zec-eu2.nanopool.org:6666
2017/10/30 05:45:02 INFO # Connected to pool zec-eu2.nanopool.org:6666
2017/10/30 05:45:02 WARN # Resetting workers...
2017/10/30 05:45:02 INFO # Subscribing to pool...
2017/10/30 05:45:02 WARN # peer M3 disconnected
2017/10/30 05:45:02 INFO # 0 peer(s) mining on this proxy
2017/10/30 05:45:02 INFO # Stratum session id 157c00000000000050ef3c3e43b91b1b
2017/10/30 05:45:02 INFO # Authorizing mining wallet t1Qrz2Nub...................
2017/10/30 05:45:02 INFO # New target : 00028f5c00000000000000000000000000000000000000000000000000000000
2017/10/30 05:45:02 INFO # Mining wallet t1Qrz2Nub................... authorization granted
2017/10/30 05:45:02 INFO # New work : 13ed4e4aa583a9cfa055b2e8e36ee3a8df2df35a2d2c15b288134f230aea54ff
2017/10/30 05:45:02 WARN # peer M4 disconnected
2017/10/30 05:45:02 INFO # 0 peer(s) mining on this proxy
2017/10/30 05:45:02 WARN # peer M1 disconnected
2017/10/30 05:45:02 INFO # 0 peer(s) mining on this proxy
2017/10/30 05:45:03 WARN # peer M2 disconnected
2017/10/30 05:45:03 INFO # 0 peer(s) mining on this proxy
2017/10/30 05:45:05 INFO # New peer connected : M3
2017/10/30 05:45:05 INFO # 1 peer(s) mining on this proxy
2017/10/30 05:45:05 INFO # New peer connected : M4
2017/10/30 05:45:05 INFO # 2 peer(s) mining on this proxy
2017/10/30 05:45:05 INFO # New peer connected : M1
2017/10/30 05:45:05 INFO # 3 peer(s) mining on this proxy
2017/10/30 05:45:06 INFO # New peer connected : M2
2017/10/30 05:45:06 INFO # 4 peer(s) mining on this proxy
2017/10/30 05:45:06 INFO # Submit work for M4
2017/10/30 05:45:06 INFO # Work from M4 accepted
2017/10/30 05:45:07 INFO # Submit work for M3
2017/10/30 05:45:07 INFO # Work from M3 accepted
2017/10/30 05:45:11 WARN # ZEC STRATUM PROXY RESTARTING...
2017/10/30 05:45:11 INFO # ZEC STRATUM PROXY STARTING...
2017/10/30 05:45:11 INFO # Connecting to zec-eu1.nanopool.org:6666
2017/10/30 05:45:12 INFO # Connected to pool zec-eu1.nanopool.org:6666
2017/10/30 05:45:12 INFO # Subscribing to pool...
2017/10/30 05:45:12 INFO # Stratum session id 46bb000000000000a05cc9dcf1ded80f
2017/10/30 05:45:12 INFO # Authorizing mining wallet t1Qrz2Nub...................
2017/10/30 05:45:12 INFO # New target : 00028f5c00000000000000000000000000000000000000000000000000000000
2017/10/30 05:45:12 INFO # Mining wallet t1Qrz2Nub................... authorization granted
2017/10/30 05:45:12 INFO # New work : 13ed4e4aa583a9cfa055b2e8e36ee3a8df2df35a2d2c15b288134f230aea54ff
2017/10/30 05:45:12 WARN # peer M2 disconnected
2017/10/30 05:45:12 INFO # 0 peer(s) mining on this proxy
2017/10/30 05:45:12 WARN # peer M3 disconnected
2017/10/30 05:45:12 INFO # 0 peer(s) mining on this proxy
2017/10/30 05:45:12 WARN # peer M4 disconnected
2017/10/30 05:45:12 INFO # 0 peer(s) mining on this proxy
2017/10/30 05:45:12 WARN # peer M1 disconnected
2017/10/30 05:45:12 INFO # 0 peer(s) mining on this proxy
/home/tax79/zecproxy/lib/pool_connector.js:85
                this.miners.broadcastToMiners(obj);
                            ^

TypeError: Cannot read property 'broadcastToMiners' of null
    at PoolConnector.onData (/home/tax79/zecproxy/lib/pool_connector.js:85:29)
    at DestroyableTransform.poolSocket.on.pipe.on (/home/tax79/zecproxy/lib/pool_connector.js:158:43)
    at emitOne (events.js:115:13)
    at DestroyableTransform.emit (events.js:210:7)
    at addChunk (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:284:12)
    at readableAddChunk (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:271:11)
    at DestroyableTransform.Readable.push (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_readable.js:238:10)
    at DestroyableTransform.Transform.push (/home/tax79/zecproxy/node_modules/ndjson/node_modules/readable-stream/lib/_stream_transform.js:146:32)
    at push (/home/tax79/zecproxy/node_modules/ndjson/node_modules/split2/index.js:52:10)
    at DestroyableTransform.transform [as _transform] (/home/tax79/zecproxy/node_modules/ndjson/node_modules/split2/index.js:33:5)
2017/10/30 05:45:22 WARN # Zcash Stratul proxy version 1.0.5
2017/10/30 05:45:22 WARN # PROXY IS LISTENING ON PORT 8000
2017/10/30 05:45:22 WARN # -----------------------------------------------------------------------
2017/10/30 05:45:22 WARN # Mining Wallet: t1Qrz2Nub...................
2017/10/30 05:45:22 WARN # Worker ID enabled: true
2017/10/30 05:45:22 WARN # Failover enabled: true
2017/10/30 05:45:22 WARN # -----------------------------------------------------------------------
2017/10/30 05:45:22 WARN # Donation ETH : 0x1212eF39d945aB9A9568Aa5a72c5CBA99Bbe46c1
2017/10/30 05:45:22 WARN # Donation ZEC : t1YAdYcnKR2ozADWPUvmgnDgf86gfsxQEEE
2017/10/30 05:45:22 WARN # -----------------------------------------------------------------------
2017/10/30 05:45:22 INFO # ZEC STRATUM PROXY STARTING...
2017/10/30 05:45:22 INFO # Connecting to zec-eu1.nanopool.org:6666
2017/10/30 05:45:22 INFO # Connected to pool zec-eu1.nanopool.org:6666
2017/10/30 05:45:22 INFO # Subscribing to pool...
2017/10/30 05:45:22 INFO # Stratum session id bfb7000000000000b756c6bd83bb8477
2017/10/30 05:45:22 INFO # Authorizing mining wallet t1Qrz2Nub...................
2017/10/30 05:45:22 INFO # New target : 00028f5c00000000000000000000000000000000000000000000000000000000
2017/10/30 05:45:22 INFO # Mining wallet t1Qrz2Nub................... authorization granted
2017/10/30 05:45:22 INFO # New work : fad7fe7e18ef79fdfb4d5dca1212b426a06b8e0c2d12057e1e9a4065a4ee2fe5
2017/10/30 05:45:22 INFO # New peer connected : M2
2017/10/30 05:45:22 INFO # 1 peer(s) mining on this proxy
2017/10/30 05:45:22 INFO # New peer connected : M3
2017/10/30 05:45:22 INFO # 2 peer(s) mining on this proxy
2017/10/30 05:45:22 INFO # New peer connected : M4
2017/10/30 05:45:22 INFO # 3 peer(s) mining on this proxy
2017/10/30 05:45:22 INFO # New peer connected : M1
2017/10/30 05:45:22 INFO # 4 peer(s) mining on this proxy
2017/10/30 05:45:22 INFO # Submit work for M2
2017/10/30 05:45:22 INFO # Work from M2 accepted
2017/10/30 05:45:23 INFO # Submit work for M3
2017/10/30 05:45:23 INFO # Work from M3 accepted
digitalshamansky commented 6 years ago

@tax79 could you please share your script?

BScrk commented 6 years ago

ok got it ! Will fix it soon

tax79 commented 6 years ago

@digitalshamansky

Name: zecproxyautorestart

#!/bin/bash

sleep 60 &&

while true; do
    pidof node > /dev/null || xterm -e /home/tax79/.zecproxy/zecproxy
    sleep 10
done

Name: zecproxy

#!/bin/bash

cd /home/tax79/zecproxy
node proxy.js 2>&1 | tee -a /home/tax79/.zecproxy/log.txt
digitalshamansky commented 6 years ago

@tax79 Thanks a lot!

BScrk commented 6 years ago

fix done, version 1.0.6 coming @tax79 @digitalshamansky can you try it ?

digitalshamansky commented 6 years ago

@BScrk Sure, just right now can pull and launch it

BScrk commented 6 years ago

ok v1.0.6 pushed

tax79 commented 6 years ago

@BScrk Just downloaded and started v1.0.6. If it crashes again I will let you know.

digitalshamansky commented 6 years ago

@BScrk already pulled and relaunched v1.0.6

BScrk commented 6 years ago

@tax79 @digitalshamansky, just pushed a new version with other (and finals I guess) robustness improvements. Enjoy

digitalshamansky commented 6 years ago

@BScrk pulled it. Thanks

BScrk commented 6 years ago

@tax79, @digitalshamansky, any updates?

tax79 commented 6 years ago

@BScrk Periodically I can see in my logs something like that:

2017/11/04 05:52:16 INFO # Work from M2 accepted
2017/11/04 05:52:16 INFO # Submit work for M3
2017/11/04 05:52:16 INFO # New work : 65c643cdece07e2bf1f84b6c752415e17b65668798969f9149fcb98cdace7a56
2017/11/04 05:52:16 INFO # Work from M3 rejected: Cannot find job
2017/11/04 05:52:16 ERROR # Too many rejected shares : 5
2017/11/04 05:52:16 WARN #  - M3 : 4 shares rejected
2017/11/04 05:52:16 WARN #  - M2 : 1 shares rejected
2017/11/04 05:52:16 WARN #  - M4 : 0 shares rejected
2017/11/04 05:52:16 WARN #  - M1 : 0 shares rejected
2017/11/04 05:52:16 ERROR # Closing all connections...
2017/11/04 05:52:16 ERROR # Waiting 10 seconds before attempting to restart the Stratum Proxy
2017/11/04 05:52:16 WARN # peer M3 disconnected
2017/11/04 05:52:16 INFO # 0 peer(s) mining on this proxy
2017/11/04 05:52:16 WARN # peer M4 disconnected
2017/11/04 05:52:16 INFO # 0 peer(s) mining on this proxy
2017/11/04 05:52:17 WARN # peer M2 disconnected
2017/11/04 05:52:17 INFO # 0 peer(s) mining on this proxy
2017/11/04 05:52:17 WARN # peer M1 disconnected
2017/11/04 05:52:17 INFO # 0 peer(s) mining on this proxy
2017/11/04 05:52:26 WARN # ZEC STRATUM PROXY RESETING...
2017/11/04 05:52:26 INFO # ZEC STRATUM PROXY 1.0.7 STARTING...
2017/11/04 05:52:26 INFO # Connecting to zec-eu1.nanopool.org:6666
2017/11/04 05:52:26 INFO # Connected to pool zec-eu1.nanopool.org:6666
2017/11/04 05:52:26 WARN # Creating workers listner...
2017/11/04 05:52:26 INFO # Subscribing to pool...
2017/11/04 05:52:26 INFO # Stratum session id 2a14010000000000a112b2bfdb4e973c
2017/11/04 05:52:26 INFO # Authorizing mining wallet t1Qrz2N................................
2017/11/04 05:52:26 INFO # New target : 00028f5c00000000000000000000000000000000000000000000000000000000
2017/11/04 05:52:26 INFO # New peer connected : M3
2017/11/04 05:52:26 ERROR # Miner failure on state none
2017/11/04 05:52:26 INFO # Mining wallet t1Qrz2N................................ authorization granted
2017/11/04 05:52:26 INFO # New work : 213421981b922363035301bb4d08497ab91d1550af34aa3e9633e76cd17c223e
2017/11/04 05:52:26 INFO # New peer connected : M4
2017/11/04 05:52:26 INFO # 2 peer(s) mining on this proxy
2017/11/04 05:52:27 INFO # New peer connected : M2
2017/11/04 05:52:27 INFO # 3 peer(s) mining on this proxy
2017/11/04 05:52:27 INFO # New peer connected : M1
2017/11/04 05:52:27 INFO # 4 peer(s) mining on this proxy
2017/11/04 05:52:29 INFO # Submit work for M1
2017/11/04 05:52:29 INFO # Work from M1 accepted
2017/11/04 05:52:29 INFO # Submit work for M2
2017/11/04 05:52:29 INFO # Work from M2 accepted

After that zecproxy works ok.

And sometimes after restarting zecproxy as it was shown above EWBF shows that it is disconnected to zecproxy server, but it is not: https://i.imgur.com/ej4MrYr.png

tax79 commented 6 years ago

@BScrk And one more thing to mention - EWBF does not show any rejected shares anymore. For me it's ok.

All I can say - Zecproxy works quite stable after update. Thanks.

tax79 commented 6 years ago

@BScrk Yes, error "Miner failure on state none" makes EWBF show that it's disconnected to zecrpoxy server.

2017/11/04 23:30:58 INFO # New peer connected : M1
2017/11/04 23:30:58 ERROR # Miner failure on state none

The previous screenshot: https://i.imgur.com/ej4MrYr.png