cjongseok / mtproto

Telegram MTProto and its proxy (over gRPC) in Go (golang). API Layer: 71
Apache License 2.0
151 stars 20 forks source link

mtproto.TL_crc_bad_msg_notification #1

Closed astravexton closed 6 years ago

astravexton commented 6 years ago

I just tried to run the simpleshell.go example and got this output in ss.log, happens every time that i try it


2017/12/06 23:29:25 [MM 1123312869] start
2017/12/06 23:29:25 [MM 1123312869] newsession to  149.154.167.50:443
2017/12/06 23:29:25 [0-3809958685979515729] dial TCP to 149.154.167.50:443
2017/12/06 23:29:26 [0-3809958685979515729] read: start
2017/12/06 23:29:26 [0-3809958685979515729] send: start
2017/12/06 23:29:26 [0-3809958685979515729] send mtproto.TL_invokeWithLayer: {"Layer":71,"Query":{"Api_id":XXXXXX,"Device_model":"Unknown","System_version":"windows/amd64","App_version":"0.0.1","System_lang_code":"en","Lang_pack":"","Lang_code":"en","Query":{}}}
2017/12/06 23:29:26 [0-3809958685979515729] read: type: mtproto.TL_msg_container, data: {[{6496580273879479297 1 28 {6496580271469954036 -820804553205492118 [14 210 25 103 155 121 76 252]}} {6496580273879524353 2 20 {[6496580271469954036]}}]}, err: <nil>
2017/12/06 23:29:26 [0-3809958685979515729] send mtproto.TL_msgs_ack: {}
2017/12/06 23:29:26 [0-3809958685979515729] read: type: mtproto.TL_rpc_result, data: {6496580271469954036 {0 1512602966 1512606504 {} 2 [{0 1 149.154.175.50 443} {1 1 2001:0b28:f23d:f001:0000:0000:0000:000a 443} {0 2 149.154.167.51 443} {16 2 149.154.167.51 443} {1 2 2001:067c:04e8:f002:0000:0000:0000:000a 443} {0 3 149.154.175.100 443} {1 3 2001:0b28:f23d:f003:0000:0000:0000:000a 443} {0 4 149.154.167.91 443} {1 4 2001:067c:04e8:f004:0000:0000:0000:000a 443} {2 4 149.154.165.120 443} {0 5 91.108.56.165 443} {1 5 2001:0b28:f23f:f005:0000:0000:0000:000a 443}] 200 30000 100 120000 5000 30000 300000 30000 1500 10 60000 2 200 172800 2419200 30 5 0 5 20000 90000 30000 10000 https://t.me/  0 []}}, err: <nil>
2017/12/06 23:29:26 [0-3809958685979515729] process: unknown data type mtproto.TL_config {{"Flags":0,"Date":1512602966,"Expires":1512606504,"Test_mode":{},"This_dc":2,"Dc_options":[{"Flags":0,"Id":1,"Ip_address":"149.154.175.50","Port":443},{"Flags":1,"Id":1,"Ip_address":"2001:0b28:f23d:f001:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":16,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":1,"Id":2,"Ip_address":"2001:067c:04e8:f002:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":3,"Ip_address":"149.154.175.100","Port":443},{"Flags":1,"Id":3,"Ip_address":"2001:0b28:f23d:f003:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":4,"Ip_address":"149.154.167.91","Port":443},{"Flags":1,"Id":4,"Ip_address":"2001:067c:04e8:f004:0000:0000:0000:000a","Port":443},{"Flags":2,"Id":4,"Ip_address":"149.154.165.120","Port":443},{"Flags":0,"Id":5,"Ip_address":"91.108.56.165","Port":443},{"Flags":1,"Id":5,"Ip_address":"2001:0b28:f23f:f005:0000:0000:0000:000a","Port":443}],"Chat_size_max":200,"Megagroup_size_max":30000,"Forwarded_count_max":100,"Online_update_period_ms":120000,"Offline_blur_timeout_ms":5000,"Offline_idle_timeout_ms":30000,"Online_cloud_timeout_ms":300000,"Notify_cloud_delay_ms":30000,"Notify_default_delay_ms":1500,"Chat_big_size":10,"Push_chat_period_ms":60000,"Push_chat_limit":2,"Saved_gifs_limit":200,"Edit_time_limit":172800,"Rating_e_decay":2419200,"Stickers_recent_limit":30,"Stickers_faved_limit":5,"Tmp_sessions":0,"Pinned_dialogs_count_max":5,"Call_receive_timeout_ms":20000,"Call_ring_timeout_ms":90000,"Call_connect_timeout_ms":30000,"Call_packet_timeout_ms":10000,"Me_url_prefix":"https://t.me/","Suggested_lang_code":"","Lang_pack_version":0,"Disabled_features":[]}}
2017/12/06 23:29:26 [0-3809958685979515729] send mtproto.TL_msgs_ack: {}
2017/12/06 23:29:26 [0-3809958685979515729] config: {"Flags":0,"Date":1512602966,"Expires":1512606504,"Test_mode":{},"This_dc":2,"Dc_options":[{"Flags":0,"Id":1,"Ip_address":"149.154.175.50","Port":443},{"Flags":1,"Id":1,"Ip_address":"2001:0b28:f23d:f001:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":16,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":1,"Id":2,"Ip_address":"2001:067c:04e8:f002:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":3,"Ip_address":"149.154.175.100","Port":443},{"Flags":1,"Id":3,"Ip_address":"2001:0b28:f23d:f003:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":4,"Ip_address":"149.154.167.91","Port":443},{"Flags":1,"Id":4,"Ip_address":"2001:067c:04e8:f004:0000:0000:0000:000a","Port":443},{"Flags":2,"Id":4,"Ip_address":"149.154.165.120","Port":443},{"Flags":0,"Id":5,"Ip_address":"91.108.56.165","Port":443},{"Flags":1,"Id":5,"Ip_address":"2001:0b28:f23f:f005:0000:0000:0000:000a","Port":443}],"Chat_size_max":200,"Megagroup_size_max":30000,"Forwarded_count_max":100,"Online_update_period_ms":120000,"Offline_blur_timeout_ms":5000,"Offline_idle_timeout_ms":30000,"Online_cloud_timeout_ms":300000,"Notify_cloud_delay_ms":30000,"Notify_default_delay_ms":1500,"Chat_big_size":10,"Push_chat_period_ms":60000,"Push_chat_limit":2,"Saved_gifs_limit":200,"Edit_time_limit":172800,"Rating_e_decay":2419200,"Stickers_recent_limit":30,"Stickers_faved_limit":5,"Tmp_sessions":0,"Pinned_dialogs_count_max":5,"Call_receive_timeout_ms":20000,"Call_ring_timeout_ms":90000,"Call_connect_timeout_ms":30000,"Call_packet_timeout_ms":10000,"Me_url_prefix":"https://t.me/","Suggested_lang_code":"","Lang_pack_version":0,"Disabled_features":[]}
2017/12/06 23:29:26 [0-3809958685979515729] send mtproto.TL_updates_getState: {}
2017/12/06 23:29:26 [0-3809958685979515729] read: type: mtproto.TL_crc_bad_msg_notification, data: {6496580271534462136 7 33}, err: <nil>
2017/12/06 23:29:26 [0-3809958685979515729] process: unknown data type mtproto.TL_crc_bad_msg_notification {{}}```
grandsilence commented 6 years ago

same

cjongseok commented 6 years ago

Thanks for your interests in my code :) Although I could not reproduce the above error, I found an issue on the new authentication with Layer-71 and fixed it. So can you guys try the new version? For a clean try, please remove your telegram auth file, /.telegram_, in advance; the auth file is created by cjongseok/mtproto so feel free to remove it. If there is still an issue, let me know the log file together with the error message, if exist.

grandsilence commented 6 years ago

Nope. Nothing working. I updated packages with -u arg. It locks at manager.NewAuthentication() method and nothing happen. Parameters is correct. Same error in logs:

2017/12/10 12:14:14 [0-987807202236328261] send mtproto.TL_updates_getState: {}
2017/12/10 12:14:14 [0-987807202236328261] read: type: mtproto.TL_crc_bad_msg_notification, data: {6497844228913168884 7 33}, err: <nil>
2017/12/10 12:14:14 [0-987807202236328261] process: unknown data type mtproto.TL_crc_bad_msg_notification {{}}
cjongseok commented 6 years ago

Did you remove auth file and touch the production Telegram server specified in your https://my.telegram.org/apps page?

astravexton commented 6 years ago

Sorry for the late reply, i still get the same error even after removing ~/.telegram_

cjongseok commented 6 years ago

I tested it on mac and linux with signed up phonenumber + valid api id/hash/server on cleaned state (i.e., no \~/.telegram~~ files) and they worked. Give me more hints for the error. Still I can not reproduce it.

astravexton commented 6 years ago

I'm getting a different error after removing all the files

2017/12/13 13:51:15 [MM 14433365] start
2017/12/13 13:51:15 [MM 14433365] newsession to  149.154.167.50:443
2017/12/13 13:51:15 [0-4072867300443788290] dial TCP to 149.154.167.50:443
2017/12/13 13:51:17 [0-4072867300443788290] read: start
2017/12/13 13:51:17 [0-4072867300443788290] send: start
2017/12/13 13:51:17 [0-4072867300443788290] send mtproto.TL_invokeWithLayer: {"Layer":71,"Query":{"Api_id":XXXXXX,"Device_model":"Unknown","System_version":"windows/amd64","App_version":"0.0.1","System_lang_code":"en","Lang_pack":"","Lang_code":"en","Query":{}}}
2017/12/13 13:51:17 [0-4072867300443788290] read: type: mtproto.TL_msg_container, data: {[{6499028881552709633 1 28 {6499028879457618992 6182303720115487009 [142 96 227 158 192 226 174 218]}} {6499028881552720897 2 20 {[6499028879457618992]}}]}, err: <nil>
2017/12/13 13:51:17 [0-4072867300443788290] send mtproto.TL_msgs_ack: {}
2017/12/13 13:51:17 [0-4072867300443788290] read: type: mtproto.TL_rpc_result, data: {6499028879457618992 {0 1513173077 1513176766 {} 2 [{0 1 149.154.175.50 443} {1 1 2001:0b28:f23d:f001:0000:0000:0000:000a 443} {0 2 149.154.167.51 443} {16 2 149.154.167.51 443} {1 2 2001:067c:04e8:f002:0000:0000:0000:000a 443} {0 3 149.154.175.100 443} {1 3 2001:0b28:f23d:f003:0000:0000:0000:000a 443} {0 4 149.154.167.91 443} {1 4 2001:067c:04e8:f004:0000:0000:0000:000a 443} {2 4 149.154.165.120 443} {0 5 91.108.56.165 443} {1 5 2001:0b28:f23f:f005:0000:0000:0000:000a 443}] 200 30000 100 120000 5000 30000 300000 30000 1500 10 60000 2 200 172800 2419200 30 5 0 5 20000 90000 30000 10000 https://t.me/  0 []}}, err: <nil>
2017/12/13 13:51:17 [0-4072867300443788290] process: unknown data type mtproto.TL_config {{"Flags":0,"Date":1513173077,"Expires":1513176766,"Test_mode":{},"This_dc":2,"Dc_options":[{"Flags":0,"Id":1,"Ip_address":"149.154.175.50","Port":443},{"Flags":1,"Id":1,"Ip_address":"2001:0b28:f23d:f001:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":16,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":1,"Id":2,"Ip_address":"2001:067c:04e8:f002:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":3,"Ip_address":"149.154.175.100","Port":443},{"Flags":1,"Id":3,"Ip_address":"2001:0b28:f23d:f003:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":4,"Ip_address":"149.154.167.91","Port":443},{"Flags":1,"Id":4,"Ip_address":"2001:067c:04e8:f004:0000:0000:0000:000a","Port":443},{"Flags":2,"Id":4,"Ip_address":"149.154.165.120","Port":443},{"Flags":0,"Id":5,"Ip_address":"91.108.56.165","Port":443},{"Flags":1,"Id":5,"Ip_address":"2001:0b28:f23f:f005:0000:0000:0000:000a","Port":443}],"Chat_size_max":200,"Megagroup_size_max":30000,"Forwarded_count_max":100,"Online_update_period_ms":120000,"Offline_blur_timeout_ms":5000,"Offline_idle_timeout_ms":30000,"Online_cloud_timeout_ms":300000,"Notify_cloud_delay_ms":30000,"Notify_default_delay_ms":1500,"Chat_big_size":10,"Push_chat_period_ms":60000,"Push_chat_limit":2,"Saved_gifs_limit":200,"Edit_time_limit":172800,"Rating_e_decay":2419200,"Stickers_recent_limit":30,"Stickers_faved_limit":5,"Tmp_sessions":0,"Pinned_dialogs_count_max":5,"Call_receive_timeout_ms":20000,"Call_ring_timeout_ms":90000,"Call_connect_timeout_ms":30000,"Call_packet_timeout_ms":10000,"Me_url_prefix":"https://t.me/","Suggested_lang_code":"","Lang_pack_version":0,"Disabled_features":[]}}
2017/12/13 13:51:17 [0-4072867300443788290] send mtproto.TL_msgs_ack: {}
2017/12/13 13:51:17 [0-4072867300443788290] config: {"Flags":0,"Date":1513173077,"Expires":1513176766,"Test_mode":{},"This_dc":2,"Dc_options":[{"Flags":0,"Id":1,"Ip_address":"149.154.175.50","Port":443},{"Flags":1,"Id":1,"Ip_address":"2001:0b28:f23d:f001:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":16,"Id":2,"Ip_address":"149.154.167.51","Port":443},{"Flags":1,"Id":2,"Ip_address":"2001:067c:04e8:f002:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":3,"Ip_address":"149.154.175.100","Port":443},{"Flags":1,"Id":3,"Ip_address":"2001:0b28:f23d:f003:0000:0000:0000:000a","Port":443},{"Flags":0,"Id":4,"Ip_address":"149.154.167.91","Port":443},{"Flags":1,"Id":4,"Ip_address":"2001:067c:04e8:f004:0000:0000:0000:000a","Port":443},{"Flags":2,"Id":4,"Ip_address":"149.154.165.120","Port":443},{"Flags":0,"Id":5,"Ip_address":"91.108.56.165","Port":443},{"Flags":1,"Id":5,"Ip_address":"2001:0b28:f23f:f005:0000:0000:0000:000a","Port":443}],"Chat_size_max":200,"Megagroup_size_max":30000,"Forwarded_count_max":100,"Online_update_period_ms":120000,"Offline_blur_timeout_ms":5000,"Offline_idle_timeout_ms":30000,"Online_cloud_timeout_ms":300000,"Notify_cloud_delay_ms":30000,"Notify_default_delay_ms":1500,"Chat_big_size":10,"Push_chat_period_ms":60000,"Push_chat_limit":2,"Saved_gifs_limit":200,"Edit_time_limit":172800,"Rating_e_decay":2419200,"Stickers_recent_limit":30,"Stickers_faved_limit":5,"Tmp_sessions":0,"Pinned_dialogs_count_max":5,"Call_receive_timeout_ms":20000,"Call_ring_timeout_ms":90000,"Call_connect_timeout_ms":30000,"Call_packet_timeout_ms":10000,"Me_url_prefix":"https://t.me/","Suggested_lang_code":"","Lang_pack_version":0,"Disabled_features":[]}
2017/12/13 13:51:17 [0-4072867300443788290] send mtproto.TL_updates_getState: {}
2017/12/13 13:51:17 [0-4072867300443788290] read: type: mtproto.TL_rpc_result, data: {6499028879522626992 {401 AUTH_KEY_UNREGISTERED}}, err: <nil>
2017/12/13 13:51:17 [0-4072867300443788290] process: unknown data type mtproto.TL_rpc_error {{}}
2017/12/13 13:51:17 [0-4072867300443788290] send mtproto.TL_msgs_ack: {}
2017/12/13 13:51:17 [MM 14433365] connectionOpened  1471635579
2017/12/13 13:51:17 [mconn 1471635579] start
2017/12/13 13:51:17 [mconn 1471635579] opened.
2017/12/13 13:51:17 [mconn 1471635579] wait for a session binding ...
2017/12/13 13:51:17 [mconn 1471635579] bind: mconn.discardedUpdatesState is nil
2017/12/13 13:51:17 [MM 14433365] sessionBound: session 4072867300443788290 is bound to mconn 1471635579
2017/12/13 13:51:17 [mconn 1471635579] bound to session 4072867300443788290
2017/12/13 13:51:17 [1471635579-4072867300443788290] send mtproto.TL_auth_sendCode: {"Flags":1,"Phone_number":"+44XXXXXXXXX","Current_number":{},"Api_id":XXXXXX,"Api_hash":"XXXXXXXXXXXXXXXXXXXXXXXXX"}
2017/12/13 13:51:17 [1471635579-4072867300443788290] read: type: mtproto.TL_rpc_result, data: {6499028879577136492 {303 PHONE_MIGRATE_4}}, err: <nil>
2017/12/13 13:51:17 [1471635579-4072867300443788290] process: unknown data type mtproto.TL_rpc_error {{}}
2017/12/13 13:51:17 [1471635579-4072867300443788290] send mtproto.TL_msgs_ack: {}
2017/12/13 13:51:17 [MM 14433365] renewSession to  149.154.165.120:443
2017/12/13 13:51:17 [mconn 1471635579] session will be discarded4072867300443788290
2017/12/13 13:51:17 [mconn 1471635579] unbound to session 4072867300443788290
2017/12/13 13:51:17 [MM 14433365] sessionUnbound: session 4072867300443788290 is unbound from mconn 1471635579
2017/12/13 13:51:17 [MM 14433365] discard session  4072867300443788290
2017/12/13 13:51:17 [1471635579-4072867300443788290] send: stop
2017/12/13 13:51:17 [1471635579-4072867300443788290] read: wait for inner routine ...
2017/12/13 13:51:17 [1471635579-4072867300443788290] read: type: <nil>, data: <nil>, err: read tcp 192.168.8.105:6114->149.154.167.50:443: use of closed network connection
2017/12/13 13:51:17 [1471635579-4072867300443788290] read: TCP connection closed (read tcp 192.168.8.105:6114->149.154.167.50:443: use of closed network connection)
2017/12/13 13:51:17 [1471635579-4072867300443788290] read: stop
2017/12/13 13:51:17 [MM 14433365] session discarded  4072867300443788290
2017/12/13 13:51:17 [MM 14433365] refreshSession  4072867300443788290
2017/12/13 13:51:17 [MM 14433365] session is discarded. keep its updates state, (json): {"Pts":0,"Qts":0,"Date":0,"Seq":0,"Unread_count":0}
2017/12/13 13:51:17 [MM 14433365] renewRoutine: req newsession
2017/12/13 13:51:17 [MM 14433365] newsession to  149.154.165.120:443
2017/12/13 13:51:17 [0-7482388398792317020] dial TCP to 149.154.165.120:443
2017/12/13 13:51:18 [MM 14433365] sessionBound: session 7482388398792317020 is bound to mconn 1471635579

after this i get this in the console output

[signal 0xc0000005 code=0x0 addr=0x0 pc=0x531ba0]

goroutine 61 [running]:
github.com/cjongseok/mtproto.(*MConn).bind(0xc0424ae000, 0xc0424e2000, 0xc057b7607b, 0xc0424ae098)
        github.com/cjongseok/mtproto/mconn.go:64 +0x110
github.com/cjongseok/mtproto.(*MManager).manageRoutine.func1(0xc042086210, 0x8775c0, 0xc04200a940)
        github.com/cjongseok/mtproto/mmanager.go:184 +0x54d
created by github.com/cjongseok/mtproto.(*MManager).manageRoutine
       github.com/cjongseok/mtproto/mmanager.go:188 +0x589
exit status 2
grandsilence commented 6 years ago

I'm using Windows os and get an error

cjongseok commented 6 years ago

I tested mtproto on Windows 7, and reproduced the first error lol. It seems I almost caught the culprit. Can you guys let me know your Windows versions?

cjongseok commented 6 years ago

I think the first error is regarding https://github.com/golang/go/issues/17696 MTProto generates new message id based on system clock, but Windows system clock resolution is so low.

grandsilence commented 6 years ago

Windows 10 x64 1607 build. LSTB edition

astravexton commented 6 years ago

Windows 10 x64 Version 1607 (OS Build 14393.447)

cjongseok commented 6 years ago

I transferred @nathan0 's second error to https://github.com/cjongseok/mtproto/issues/2