fabianonline / telegram_backup

Java app to download all your telegram data.
GNU General Public License v3.0
450 stars 91 forks source link

400: MESSAGE_IDS_EMPTY on downloading channel #68

Open mgrandi opened 6 years ago

mgrandi commented 6 years ago

running java -jar telegram_backup.jar --target . --with-channels --with-supergroups with version 1.1.0, i get this every time i try to download a specific channel:

338200...338400...338600...338800...339000...339200...339400...339600...339800...340000...340200...340400...340600...340800...341000...341157 done.
Downloading 430490 messages from channel <CHANNEL_NAME_HERE>
400: MESSAGE_IDS_EMPTY
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries(DefaultTelegramClient.kt:209)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries$default(DefaultTelegramClient.kt:181)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries(DefaultTelegramClient.kt:160)
        at com.github.badoualy.telegram.api.TelegramClient$DefaultImpls.executeRpcQuery(TelegramClient.kt:53)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQuery(DefaultTelegramClient.kt:157)
        at com.github.badoualy.telegram.tl.api.TelegramApiWrapper.channelsGetMessages(TelegramApiWrapper.java:338)
        at de.fabianonline.telegram_backup.DownloadManager.downloadMessages(DownloadManager.java:257)
        at de.fabianonline.telegram_backup.DownloadManager._downloadMessages(DownloadManager.java:222)
        at de.fabianonline.telegram_backup.DownloadManager.downloadMessages(DownloadManager.java:78)
        at de.fabianonline.telegram_backup.CommandLineController.<init>(CommandLineController.java:146)
        at de.fabianonline.telegram_backup.CommandLineRunner.main(CommandLineRunner.java:41)

----- EXIT -----

if anything, the channel should be skipped and shouldn't cause the app to exit

fabianonline commented 6 years ago

Interesting... Can you please run the tool with --trace (and maybe also with --anonymize) and send me the last handful of lines from the output?

mgrandi commented 6 years ago

sure, here it is. Its consistently the same channel every time, so i'm thinking there is some assumption about this field being 'non empty' that isn't always correct

11:08:33.903 DEBUG Utils.getNewestVersion             : Requesting current release info from https://api.github.com/repos/fabianonline/telegram_backup/releases
11:08:35.340 DEBUG Utils.getNewestVersion             : Found current release version 1.1.0
11:08:35.343 DEBUG Utils.compareVersions              : Comparing versions 1.1.0 and 1.1.0.
11:08:35.365 INFO  CommandLineController.<init>       : CommandLineController started. App version 1.1.0
Telegram_Backup version 1.1.0, Copyright (C) 2016, 2017 Fabian Schlenz

Telegram_Backup comes with ABSOLUTELY NO WARRANTY. This is free software, and you are
welcome to redistribute it under certain conditions; run it with '--license' for details.

11:08:35.370 DEBUG CommandLineController.setupFileBase: Target dir at startup: /aaaa/aaaa/.aaaaaaaa_aaaaaa (ANONYMIZED)
11:08:35.371 DEBUG CommandLineController.setupFileBase: Target dir after options: . (ANONYMIZED)
Base directory for files: . (ANONYMIZED)
11:08:35.372 DEBUG CommandLineController.<init>       : Initializing TelegramApp
11:08:35.376 TRACE CommandLineController.<init>       : Checking accounts
Using only available account: +11111111111 (ANONYMIZED)
11:08:35.384 DEBUG CommandLineController.selectAccount: accounts.size(): 1
11:08:35.385 DEBUG CommandLineController.selectAccount: account: +11111111111 (ANONYMIZED)
11:08:35.386 DEBUG CommandLineController.<init>       : CommandLineOptions.cmd_login: false
11:08:35.387 INFO  CommandLineController.<init>       : Initializing ApiStorage
11:08:35.390 INFO  CommandLineController.<init>       : Initializing TelegramUpdateHandler
11:08:35.401 INFO  CommandLineController.<init>       : Creating Client
11:08:35.403 WARN  Kotlogram.<init>                   :
         __  ___   ______   .___________. __        ______     _______ .______          ___      .___  ___.
        |  |/  /  /  __  \  |           ||  |      /  __  \   /  _____||   _  \        /   \     |   \/   |
        |  '  /  |  |  |  | `---|  |----`|  |     |  |  |  | |  |  __  |  |_)  |      /  ^  \    |  \  /  |
        |    <   |  |  |  |     |  |     |  |     |  |  |  | |  | |_ | |      /      /  /_\  \   |  |\/|  |
        |  .  \  |  `--'  |     |  |     |  `----.|  `--'  | |  |__| | |  |\  \----./  _____  \  |  |  |  |
        |__|\__\  \______/      |__|     |_______| \______/   \______| | _| `._____/__/     \__\ |__|  |__|
        Using layer 53

11:08:35.731 DEBUG TelegramClient.init                : init() false
11:08:36.157 INFO  MTProtoTcpConnection.<init>        : Using abridged protocol
11:08:36.161 INFO  MTProtoTcpConnection.<init>        : Connected to 149.154.175.100:443 isConnected: true, isOpen: true
11:08:36.162 DEBUG MTProtoHandler.<init>              : New handler from existing key
11:08:36.162 INFO  MTProtoHandler.startWatchdog       : startWatchdog()
11:08:36.240 INFO  MTProtoWatchdog.call               : Adding -7803804982140189380 to watchdog
11:08:36.245 DEBUG TelegramClient.initConnection      : Init connection with method updates.getState#edd4882a
11:08:36.258 DEBUG MTProtoHandler.executeMethods      : executeMethod invokeWithLayer#da9b0d0d
11:08:36.271 DEBUG MTProtoHandler.getAckToSend        : No extra ack to send
11:08:36.277 INFO  MTProtoHandler.call                : Sending method invokeWithLayer#da9b0d0d with msgId 6500950614774644736 and seqNo 1
11:08:36.278 DEBUG MTProtoHandler.call                : Sending single method
11:08:36.278 DEBUG MTProtoHandler.sendMessage         : Sending message with msgId 6500950614774644736 and seqNo 1
11:08:36.320 INFO  MTProtoWatchdog.readMessage        : [-7803804982140189380] readMessage()
11:08:36.322 DEBUG MTProtoTcpConnection.readMessage   : About to read a message of length 88
11:08:36.323 DEBUG MTProtoWatchdog.readMessage        : [-7803804982140189380] New message of length: 88
11:08:36.325 DEBUG MTProtoHandler.onMessageReceived   : Received msg 6500950616088336385 with seqNo 0
11:08:36.325 TRACE MTProtoHandler.deserializeMessageCo: Reading constructor -307542917
11:08:36.331 TRACE MTProtoHandler.deserializeMessageCo: -307542917 is supported by MTProtoContext
11:08:36.332 DEBUG MTProtoHandler.handleMessage       : handle bad_server_salt#edab447b
11:08:36.333 ERROR MTProtoHandler.handleMessage       : {id: 6500950614774644736, seqNo: 1, errorCode: 48, errorMessage: incorrect server salt}
11:08:36.334 WARN  MTProtoHandler.handleMessage       : Re-sending message 6500950614774644736 with new salt
11:08:36.334 DEBUG MTProtoHandler.sendMessage         : Sending message with msgId 6500950614774644736 and seqNo 1
11:08:36.367 INFO  MTProtoWatchdog.readMessage        : [-7803804982140189380] readMessage()
11:08:36.368 DEBUG MTProtoTcpConnection.readMessage   : About to read a message of length 152
11:08:36.368 DEBUG MTProtoWatchdog.readMessage        : [-7803804982140189380] New message of length: 152
11:08:36.369 DEBUG MTProtoHandler.onMessageReceived   : Received msg 6500950616295366657 with seqNo 2
11:08:36.369 TRACE MTProtoHandler.onMessageReceived   : Message is a container
11:08:36.370 TRACE MTProtoHandler.onMessageReceived   : Container has 2 items
11:08:36.373 TRACE MTProtoHandler.deserializeMessageCo: Reading constructor -1631450872
11:08:36.373 TRACE MTProtoHandler.deserializeMessageCo: -1631450872 is supported by MTProtoContext
11:08:36.374 DEBUG MTProtoHandler.handleMessage       : handle new_session_created#9ec20908
11:08:36.378 INFO  MTProtoWatchdog.readMessage        : [-7803804982140189380] readMessage()
11:08:36.378 DEBUG MTProtoTcpConnection.readMessage   : About to read a message of length 104
11:08:36.378 DEBUG MTProtoWatchdog.readMessage        : [-7803804982140189380] New message of length: 104
11:08:36.379 TRACE MTProtoHandler.sendMessageAck      : Adding msgId 6500950616295339009 to bufferId 0
11:08:36.385 TRACE MTProtoHandler.deserializeMessageCo: Reading constructor 1658238041
11:08:36.386 TRACE MTProtoHandler.deserializeMessageCo: 1658238041 is supported by MTProtoContext
11:08:36.387 DEBUG MTProtoHandler.handleMessage       : handle msgs_ack#62d6b459
11:08:36.387 DEBUG MTProtoHandler.handleMessage       : Received ack for 6500950614774644736
11:08:36.388 DEBUG MTProtoHandler.onMessageReceived   : Received msg 6500950616342657025 with seqNo 3
11:08:36.388 TRACE MTProtoHandler.deserializeMessageCo: Reading constructor -212046591
11:08:36.388 TRACE MTProtoHandler.deserializeMessageCo: -212046591 is supported by MTProtoContext
11:08:36.389 DEBUG MTProtoHandler.handleMessage       : handle rpc_result#f35c6d01
11:08:36.389 DEBUG MTProtoHandler.handleResult        : Got result for msgId 6500950614774644736
11:08:36.389 DEBUG MTProtoHandler.handleResult        : Response is a -1519637954
11:08:36.391 INFO  TelegramClient.<init>              : Client ready
11:08:36.392 INFO  CommandLineController.<init>       : Initializing UserManager
11:08:36.392 DEBUG UserManager.<init>                 : Calling getFullUser
11:08:36.393 DEBUG MTProtoHandler.executeMethods      : executeMethod users.getFullUser#ca30a5b1
11:08:36.403 TRACE MTProtoHandler.sendMessageAck      : Adding msgId 6500950616342657025 to bufferId 1
11:08:36.418 DEBUG MTProtoHandler.getAckToSend        : Building ack for messages 6500950616295339009 with msgId 6500950614774644740 and seqNo 2
11:08:36.419 INFO  MTProtoHandler.call                : Sending method users.getFullUser#ca30a5b1 with msgId 6500950614774644744 and seqNo 3
11:08:36.420 DEBUG MTProtoHandler.call                : Sending methods in container
11:08:36.420 DEBUG MTProtoHandler.sendMessage         : Sending message with msgId 6500950614774644748 and seqNo 4
11:08:36.458 INFO  MTProtoWatchdog.readMessage        : [-7803804982140189380] readMessage()
11:08:36.459 DEBUG MTProtoTcpConnection.readMessage   : About to read a message of length 344
11:08:36.459 DEBUG MTProtoWatchdog.readMessage        : [-7803804982140189380] New message of length: 344
11:08:36.460 DEBUG MTProtoHandler.onMessageReceived   : Received msg 6500950616688274433 with seqNo 5
11:08:36.462 TRACE MTProtoHandler.deserializeMessageCo: Reading constructor -212046591
11:08:36.462 TRACE MTProtoHandler.deserializeMessageCo: -212046591 is supported by MTProtoContext
11:08:36.462 DEBUG MTProtoHandler.handleMessage       : handle rpc_result#f35c6d01
11:08:36.462 DEBUG MTProtoHandler.handleResult        : Got result for msgId 6500950614774644744
11:08:36.463 DEBUG MTProtoHandler.handleResult        : Response is a 812830625
11:08:36.466 DEBUG CommandLineController.<init>       : CommandLineOptions.cmd_login: false
11:08:36.468 TRACE MTProtoHandler.sendMessageAck      : Adding msgId 6500950616688274433 to bufferId 1
Opening database...
11:08:36.613 DEBUG DatabaseUpdates.<init>             : Registering Database Updates...
11:08:36.615 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_1 as update to version 1
11:08:36.619 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_2 as update to version 2
11:08:36.621 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_3 as update to version 3
11:08:36.629 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_4 as update to version 4
11:08:36.629 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_5 as update to version 5
11:08:36.630 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_6 as update to version 6
11:08:36.631 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_7 as update to version 7
11:08:36.632 DEBUG DatabaseUpdates.register           : Registering de.fabianonline.telegram_backup.DB_Update_8 as update to version 8
11:08:36.632 DEBUG DatabaseUpdates.doUpdates          : DatabaseUpdate.doUpdates running
11:08:36.633 DEBUG DatabaseUpdates.doUpdates          : Getting current database version
11:08:36.633 DEBUG DatabaseUpdates.doUpdates          : Checking if table database_versions exists
11:08:36.635 DEBUG DatabaseUpdates.doUpdates          : Table exists. Checking max version
11:08:36.636 DEBUG DatabaseUpdates.doUpdates          : version: 8
Database version: 8
11:08:36.637 DEBUG DatabaseUpdates.doUpdates          : Max available database version is 8
11:08:36.644 DEBUG DatabaseUpdates.doUpdates          : No update necessary.
Database is ready.
11:08:36.645 DEBUG CommandLineController.<init>       : CommandLineOptions.val_export: null
You are logged in as Aaaaaa Aaaaaaa (@AaaaaaAaaaaaa) (ANONYMIZED)
11:08:36.647 INFO  CommandLineController.<init>       : Initializing Download Manager
11:08:36.651 DEBUG CommandLineController.<init>       : Calling DownloadManager.downloadMessages with limit null
11:08:36.652 INFO  DownloadManager._downloadMessages  : This is _downloadMessages with limit null
11:08:36.656 INFO  DownloadManager._downloadMessages  : Downloading the last 100 dialogs
Downloading most recent dialogs...
11:08:36.658 DEBUG MTProtoHandler.executeMethods      : executeMethod messages.getDialogs#6b47f94d
11:08:36.659 DEBUG MTProtoHandler.getAckToSend        : Building ack for messages 6500950616342657025, 6500950616688274433 with msgId 6500950614774644752 and seqNo 4
11:08:36.660 INFO  MTProtoHandler.call                : Sending method messages.getDialogs#6b47f94d with msgId 6500950614774644756 and seqNo 5
11:08:36.660 DEBUG MTProtoHandler.call                : Sending methods in container
11:08:36.665 DEBUG MTProtoHandler.sendMessage         : Sending message with msgId 6500950614774644760 and seqNo 6
11:08:36.798 INFO  MTProtoWatchdog.readMessage        : [-7803804982140189380] readMessage()
11:08:36.799 DEBUG MTProtoTcpConnection.readMessage   : About to read a message of length 15656
11:08:36.832 DEBUG MTProtoWatchdog.readMessage        : [-7803804982140189380] New message of length: 15656
11:08:36.856 DEBUG MTProtoHandler.onMessageReceived   : Received msg 6500950618144108545 with seqNo 7
11:08:36.857 TRACE MTProtoHandler.deserializeMessageCo: Reading constructor -212046591
11:08:36.858 TRACE MTProtoHandler.deserializeMessageCo: -212046591 is supported by MTProtoContext
11:08:36.858 DEBUG MTProtoHandler.handleMessage       : handle rpc_result#f35c6d01
11:08:36.861 DEBUG MTProtoHandler.handleResult        : Got result for msgId 6500950614774644756
11:08:36.861 DEBUG MTProtoHandler.handleResult        : Response is a 812830625
11:08:36.915 DEBUG DownloadManager._downloadMessages  : Got 100 dialogs
11:08:36.917 TRACE DownloadManager._downloadMessages  : Updating top message id: 0 => 416055. Dialog type: com.github.badoualy.telegram.tl.api.TLPeerUser
Top message ID is 416055
11:08:36.924 TRACE MTProtoHandler.sendMessageAck      : Adding msgId 6500950618144108545 to bufferId 2
Top message ID in database is 416055
No new messages to download.
11:08:37.074 INFO  DownloadManager._downloadMessages  : Searching for missing messages in the db
Checking message database for completeness...
11:08:37.204 DEBUG DownloadManager._downloadMessages  : db_count: 2289849
11:08:37.205 DEBUG DownloadManager._downloadMessages  : db_max: 416055
Processing channels and/or supergroups...
Please note that only channels/supergroups in the last 100 active chats are processed.
Downloading 433075 messages from aaaaaaa Aaaaaaa aa Aaaaaaa (Aaaaaaaa) 11+ (ANONYMIZED)
11:08:37.427 DEBUG DownloadManager.downloadMessages   : Entering download loop
11:08:37.430 TRACE DownloadManager.downloadMessages   : Loop
11:08:37.437 TRACE DownloadManager.downloadMessages   : download_count: 200
11:08:37.438 TRACE DownloadManager.downloadMessages   : vector.size(): 200
11:08:37.438 TRACE DownloadManager.downloadMessages   : ids.size(): 432875
11:08:37.439 TRACE DownloadManager.downloadMessages   : Trying getMessages(), tries=0
11:08:37.440 DEBUG MTProtoHandler.executeMethods      : executeMethod channels.getMessages#93d7b347
11:08:37.441 DEBUG MTProtoHandler.getAckToSend        : Building ack for messages 6500950618144108545 with msgId 6500950619069612032 and seqNo 6
11:08:37.448 INFO  MTProtoHandler.call                : Sending method channels.getMessages#93d7b347 with msgId 6500950619069612036 and seqNo 7
11:08:37.449 DEBUG MTProtoHandler.call                : Sending methods in container
11:08:37.452 DEBUG MTProtoHandler.sendMessage         : Sending message with msgId 6500950619069612040 and seqNo 8
11:08:37.494 INFO  MTProtoWatchdog.readMessage        : [-7803804982140189380] readMessage()
11:08:37.495 DEBUG MTProtoTcpConnection.readMessage   : About to read a message of length 104
11:08:37.496 DEBUG MTProtoWatchdog.readMessage        : [-7803804982140189380] New message of length: 104
11:08:37.497 DEBUG MTProtoHandler.onMessageReceived   : Received msg 6500950621137277953 with seqNo 9
11:08:37.498 TRACE MTProtoHandler.deserializeMessageCo: Reading constructor -212046591
11:08:37.499 TRACE MTProtoHandler.deserializeMessageCo: -212046591 is supported by MTProtoContext
11:08:37.499 DEBUG MTProtoHandler.handleMessage       : handle rpc_result#f35c6d01
11:08:37.500 DEBUG MTProtoHandler.handleResult        : Got result for msgId 6500950619069612036
11:08:37.501 DEBUG MTProtoHandler.handleResult        : Response is a 558156313
11:08:37.503 ERROR MTProtoHandler.handleResult        : rpcError 400: MESSAGE_IDS_EMPTY
11:08:37.506 ERROR TelegramClient.executeRpcQueries   : Unhandled RpcError 400: MESSAGE_IDS_EMPTY
400: MESSAGE_IDS_EMPTY
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries(DefaultTelegramClient.kt:209)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries$default(DefaultTelegramClient.kt:181)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries(DefaultTelegramClient.kt:160)
        at com.github.badoualy.telegram.api.TelegramClient$DefaultImpls.executeRpcQuery(TelegramClient.kt:53)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQuery(DefaultTelegramClient.kt:157)
        at com.github.badoualy.telegram.tl.api.TelegramApiWrapper.channelsGetMessages(TelegramApiWrapper.java:338)
        at de.fabianonline.telegram_backup.DownloadManager.downloadMessages(DownloadManager.java:257)
        at de.fabianonline.telegram_backup.DownloadManager._downloadMessages(DownloadManager.java:222)
        at de.fabianonline.telegram_backup.DownloadManager.downloadMessages(DownloadManager.java:78)
        at de.fabianonline.telegram_backup.CommandLineController.<init>(CommandLineController.java:146)
        at de.fabianonline.telegram_backup.CommandLineRunner.main(CommandLineRunner.java:41)
11:08:37.513 TRACE MTProtoHandler.sendMessageAck      : Adding msgId 6500950621137277953 to bufferId 3
11:08:37.521 ERROR CommandLineController.<init>       : Exception caught!
com.github.badoualy.telegram.tl.exception.RpcErrorException: 400: MESSAGE_IDS_EMPTY
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries(DefaultTelegramClient.kt:209)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries$default(DefaultTelegramClient.kt:181)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQueries(DefaultTelegramClient.kt:160)
        at com.github.badoualy.telegram.api.TelegramClient$DefaultImpls.executeRpcQuery(TelegramClient.kt:53)
        at com.github.badoualy.telegram.api.DefaultTelegramClient.executeRpcQuery(DefaultTelegramClient.kt:157)
        at com.github.badoualy.telegram.tl.api.TelegramApiWrapper.channelsGetMessages(TelegramApiWrapper.java:338)
        at de.fabianonline.telegram_backup.DownloadManager.downloadMessages(DownloadManager.java:257)
        at de.fabianonline.telegram_backup.DownloadManager._downloadMessages(DownloadManager.java:222)
        at de.fabianonline.telegram_backup.DownloadManager.downloadMessages(DownloadManager.java:78)
        at de.fabianonline.telegram_backup.CommandLineController.<init>(CommandLineController.java:146)
        at de.fabianonline.telegram_backup.CommandLineRunner.main(CommandLineRunner.java:41)
11:08:37.526 INFO  MTProtoHandler.close               : close()
11:08:37.527 DEBUG MTProtoHandler.sendMessagesAck     : Sending ack for messages 6500950621137277953 with ackMsgId 6500950619069612044
11:08:37.528 DEBUG MTProtoHandler.sendMessage         : Sending message with msgId 6500950619069612044 and seqNo 8
11:08:37.529 INFO  MTProtoWatchdog.stop               : Stopping -7803804982140189380
11:08:37.531 WARN  MTProtoWatchdog.run                : Stopping watchdog...
11:08:37.531 DEBUG MTProtoTcpConnection.close         : Closing connection
11:08:37.532 WARN  Kotlogram.cleanUp                  : ==================== CLEANING ====================
11:08:37.536 WARN  MTProtoHandler.cleanUp             : cleanUp()
11:08:37.537 WARN  MTProtoWatchdog.cleanUp            : ==================== SHUTTING DOWN WATCHDOG ====================
11:08:37.540 WARN  Kotlogram.cleanUp                  : ==================== CLEANED ====================

----- EXIT -----
mgrandi commented 6 years ago

oops, didn't mean to close

mgrandi commented 6 years ago

This might have been a telegram bug that they fixed on their side, I randomly tried again and it worked, i'll try again and see if it works consistently now

fabianonline commented 6 years ago

Did it ever happen again? From your logs it looks like the tool did everything exactly as it should...