9seconds/mtg

v2.1.3 version cannot send attachment

pexcn opened this issue · 3 comments

pexcn commented

When I turned on the debug mode, I saw the following log:

{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy","timestamp":1638499196888,"message":"Stream has been started"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy","timestamp":1638499197177,"message":"Stream has been started"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy.relay","timestamp":1638499197797,"message":"telegram -> client has been finished (written 14544 bytes): invalid type: unknown type 0x4a"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy.relay","timestamp":1638499197975,"message":"client -> telegram has been finished"}
{"level":"info","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy","timestamp":1638499197975,"message":"Stream has been finished"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy.relay","timestamp":1638499198086,"message":"telegram -> client has been finished (written 14504 bytes): invalid type: unknown type 0xf7"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy.relay","timestamp":1638499198263,"message":"client -> telegram has been finished"}
{"level":"info","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy","timestamp":1638499198263,"message":"Stream has been finished"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy","timestamp":1638499202310,"message":"Stream has been started"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy","timestamp":1638499202622,"message":"Stream has been started"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy.relay","timestamp":1638499203222,"message":"telegram -> client has been finished (written 14626 bytes): invalid type: unknown type 0xf5"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"xxxxxxxxxxxxxxxxxxxxxx","logger":"proxy.relay","timestamp":1638499203404,"message":"client -> telegram has been finished"}

UPDATE:
when I use v2.1.2, I got those error log:

{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"6xUmFdKpaHqJoJtneBxTLw","logger":"proxy.relay","timestamp":1638500048536,"message":"cannot pump west -> east (written 413 bytes): %!w(*fmt.wrapError=&{cannot read type: read tcp 107.174.253.174:990->xx.xx.xx.xx:9805: use of closed network connection 0xc000341a90})"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"x5TjACsIAWg6HLJWriN8Qw","logger":"proxy","timestamp":1638500048700,"message":"Stream has been started"}
{"level":"info","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"6xUmFdKpaHqJoJtneBxTLw","logger":"proxy","timestamp":1638500048718,"message":"Stream has been finished"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"-JBIvMTe9BAA1JQG1H2fvg","logger":"proxy.relay","timestamp":1638500066684,"message":"cannot pump east -> west (written 275 bytes): %!w(*net.OpError=&{read tcp4 0xc000335710 0xc000335740 0xdd42e0})"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"-JBIvMTe9BAA1JQG1H2fvg","logger":"proxy.relay","timestamp":1638500066840,"message":"cannot pump west -> east (written 443 bytes): %!w(*fmt.wrapError=&{cannot read type: read tcp 107.174.253.174:990->xx.xx.xx.xx:9807: use of closed network connection 0xc00034c280})"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"WoBYj7ObTFleT-denu4xZA","logger":"proxy","timestamp":1638500067001,"message":"Stream has been started"}
{"level":"info","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"-JBIvMTe9BAA1JQG1H2fvg","logger":"proxy","timestamp":1638500067017,"message":"Stream has been finished"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"x5TjACsIAWg6HLJWriN8Qw","logger":"proxy.relay","timestamp":1638500091687,"message":"cannot pump east -> west (written 285 bytes): %!w(*net.OpError=&{read tcp4 0xc000335b30 0xc000335b60 0xdd42e0})"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"x5TjACsIAWg6HLJWriN8Qw","logger":"proxy.relay","timestamp":1638500091845,"message":"cannot pump west -> east (written 336 bytes): %!w(*fmt.wrapError=&{cannot read type: read tcp 107.174.253.174:990->xx.xx.xx.xx:9808: use of closed network connection 0xc00034ca50})"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"VA8iLeFN7dzPwjK0_fp5wg","logger":"proxy","timestamp":1638500092010,"message":"Stream has been started"}
{"level":"info","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"x5TjACsIAWg6HLJWriN8Qw","logger":"proxy","timestamp":1638500092021,"message":"Stream has been finished"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"WoBYj7ObTFleT-denu4xZA","logger":"proxy.relay","timestamp":1638500095941,"message":"cannot pump east -> west (written 202 bytes): %!w(*net.OpError=&{read tcp4 0xc000335f50 0xc000335f80 0xdd42e0})"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"WoBYj7ObTFleT-denu4xZA","logger":"proxy.relay","timestamp":1638500096091,"message":"cannot pump west -> east (written 34909 bytes): %!w(*fmt.wrapError=&{cannot read payload: read tcp 107.174.253.174:990->xx.xx.xx.xx:9809: use of closed network connection 0xc00034d220})"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"UEnHHwrKpEU9Rpix2fRNCg","logger":"proxy","timestamp":1638500096270,"message":"Stream has been started"}
{"level":"info","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"WoBYj7ObTFleT-denu4xZA","logger":"proxy","timestamp":1638500096273,"message":"Stream has been finished"}
{"level":"info","client-ip":"xx.xx.xx.xx","stream-id":"7fQ0Gy5OaTdu2NldbhhUDg","logger":"proxy","timestamp":1638500098403,"message":"Stream has been started"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"7fQ0Gy5OaTdu2NldbhhUDg","logger":"proxy.relay","timestamp":1638500099091,"message":"cannot pump west -> east (written 134 bytes): %!w(*fmt.wrapError=&{cannot read type: EOF 0xc000052110})"}
{"level":"debug","dc":1,"client-ip":"xx.xx.xx.xx","stream-id":"7fQ0Gy5OaTdu2NldbhhUDg","logger":"proxy.relay","timestamp":1638500099269,"message":"cannot pump east -> west (written 88 bytes): %!w(*net.OpError=&{read tcp4 0xc000350b40 0xc000350b70 {}})"}
pexcn commented

the boot command is:

/usr/local/bin/mtg simple-run 0.0.0.0:xxx xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx --timeout=30s --prefer-ip=prefer-ipv4 --doh-ip=8.8.8.8 -d

Thanks. Additional logs show me that this part of the protocol is sensitive to timings which was kinda really unexpected. I'm going to make a hotfix release later today

pexcn commented

Thank you :)