grammers icon indicating copy to clipboard operation
grammers copied to clipboard

Error 400: CHANNEL_INVALID caused by channels.readHistory

Open George-Miao opened this issue 3 years ago • 3 comments

Error

request error: rpc error 400: CHANNEL_INVALID caused by channels.readHistory

Code with issue, mainly Message#mark_as_read:

while let Some(update) = tokio::select! {
        _ = tokio::signal::ctrl_c() => Ok(None),
        result = client.next_update() => result,
    }? {
        match update {
            Update::NewMessage(mut message) if !message.outgoing() => {
                let chat = message.chat();
                info!("{:?}", chat.pack());
                let msg = message.text();
                info!("Message from {}: {}", chat.name(), msg);
                message.mark_as_read().await?; // <- Here
            }
            _ => {}
        }
        tick.tick().await;
    }

It seems like telegram is not happy for sending channels::ReadHistory to mark a message from group as read. Every time I received a message from a mega group it panics. I have tried 0.3.0 on crates.io and master branch on GitHub, both have the same issue.

Code

use std::{
    env,
    io::{BufRead, Write},
    time::Duration,
};

use color_eyre::Result;
use grammers_client::{Client, Config, InitParams, SignInError, Update};
use grammers_session::Session;
use log::info;
use tokio::runtime;

fn prompt(message: &str) -> Result<String> {
    use std::io;

    let stdout = io::stdout();
    let mut stdout = stdout.lock();
    stdout.write_all(message.as_bytes())?;
    stdout.flush()?;

    let stdin = io::stdin();
    let mut stdin = stdin.lock();

    let mut line = String::new();
    stdin.read_line(&mut line)?;
    Ok(line)
}

async fn async_main() -> Result<()> {
    simple_logger::SimpleLogger::new()
        .with_level(log::LevelFilter::Info)
        .with_module_level("grammers_session", log::LevelFilter::Info)
        .init()
        .unwrap();

    let api_id = env::var("TG_ID")?.parse().expect("TG_ID invalid");
    let api_hash = env::var("TG_HASH")?;
    let session_file = env::var("SESSION")?;

    info!("Connecting to Telegram...");

    let mut client = Client::connect(Config {
        session: Session::load_file_or_create(&session_file)?,
        api_id,
        api_hash: api_hash.to_string(),
        params: InitParams {
            catch_up: true,
            flood_sleep_threshold: Some(1),
            ..Default::default()
        },
    })
    .await?;

    info!("Connected!");

    if !client.is_authorized().await? {
        info!("Signing in...");
        let phone = prompt("Enter your phone number (international format): ")?;
        let token = client.request_login_code(&phone, api_id, &api_hash).await?;
        let code = prompt("Enter the code you received: ")?;
        let signed_in = client.sign_in(&token, &code).await;
        match signed_in {
            Err(SignInError::PasswordRequired(password_token)) => {
                let hint = password_token
                    .hint()
                    .map(String::as_str)
                    .unwrap_or_default();
                let prompt_message = format!("Enter the password (hint {}): ", &hint);
                let password = prompt(prompt_message.as_str())?;

                client
                    .check_password(password_token, password.trim())
                    .await?;
            }
            Ok(_) => (),
            Err(e) => panic!("{}", e),
        };
        info!("Signed in!");
        match client.session().save_to_file(&session_file) {
            Ok(_) => {}
            Err(e) => {
                info!(
                    "NOTE: failed to save the session, will sign out when done: {}",
                    e
                );
                client.sign_out().await?;
            }
        }
    }
    let me = client.get_me().await?;

    info!("Logged in as @{}", me.username().unwrap_or("unknown"));

    info!("Waiting for messages...");

    let mut tick = tokio::time::interval(Duration::from_millis(500));

    while let Some(update) = tokio::select! {
        _ = tokio::signal::ctrl_c() => Ok(None),
        result = client.next_update() => result,
    }? {
        match update {
            Update::NewMessage(mut message) if !message.outgoing() => {
                let chat = message.chat();
                info!("{:?}", chat.pack());
                let msg = message.text();
                info!("Message from {}: {}", chat.name(), msg);
                message.mark_as_read().await?;
            }
            _ => {}
        }
        tick.tick().await;
    }

    info!("Saving session file and exiting...");
    client.sync_update_state();
    client.session().save_to_file(&session_file)?;
    Ok(())
}

fn main() -> Result<()> {
    color_eyre::install()?;
    runtime::Builder::new_multi_thread()
        .enable_all()
        .build()
        .unwrap()
        .block_on(async_main())
}

George-Miao avatar Feb 17 '22 23:02 George-Miao

Thank you for the detailed report. Can you show the output of info!("{:?}", chat.pack());? The error seems to hint that the access hash is wrong.

Lonami avatar Feb 18 '22 08:02 Lonami

Thank you for the detailed report. Can you show the output of info!("{:?}", chat.pack());? The error seems to hint that the access hash is wrong.

Yes. Here is the output along with some backtrace, which I won't consider useful because of all the noise from tokio.

2022-02-18T13:38:05.934Z INFO [teler] Connecting to Telegram...
2022-02-18T13:38:05.949Z INFO [grammers_mtsender] connecting...
2022-02-18T13:38:06.040Z INFO [grammers_mtproto::mtp::encrypted] got bad salt; asking for more salts
2022-02-18T13:38:06.040Z INFO [grammers_mtsender] request error: bad message (code 48, incorrect server salt); re-sending request MsgId(7066043627713226560)
2022-02-18T13:38:06.088Z INFO [grammers_mtproto::mtp::encrypted] got 64 future salts
2022-02-18T13:38:06.088Z INFO [grammers_mtsender] got rpc result MsgId(7066043628190705856) but no such request is saved
2022-02-18T13:38:06.093Z INFO [teler] Connected!
2022-02-18T13:38:06.211Z INFO [teler] Waiting for messages...
2022-02-18T13:38:08.194Z INFO [grammers_session::message_box] gap on update for Channel(1066867565) (local 1085750, count 1, remote 1085766)
2022-02-18T13:38:08.194Z INFO [grammers_session::message_box] gap on update for Channel(1066867565) (local 1085750, count 1, remote 1085766)
2022-02-18T13:38:08.696Z INFO [grammers_session::message_box] gap was not resolved after waiting for Channel(1066867565)
2022-02-18T13:38:08.784Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:08.784Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:08.844Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:08.844Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:08.919Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:08.919Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:09.000Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:09.000Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:09.098Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:09.098Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:09.194Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:09.194Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:09.276Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:09.276Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:09.342Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:09.342Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:09.712Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:09.712Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:10.213Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:10.214Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:10.713Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:10.713Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:11.213Z INFO [teler] PackedChat { ty: Megagroup, id: 1066867565, access_hash: Some(-890626358942336100) }
2022-02-18T13:38:11.213Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:11.713Z INFO [teler] PackedChat { ty: Megagroup, id: 1031857103, access_hash: Some(-6801900178457002071) }
2022-02-18T13:38:11.713Z INFO [teler] Message from [: REDACTED :]
2022-02-18T13:38:11.713Z INFO [teler] PackedChat { ty: Megagroup, id: 1031857103, access_hash: Some(-6801900178457002071) }
2022-02-18T13:38:11.713Z INFO [teler] Message from [: REDACTED :]
Error:
   0: request error: rpc error 400: CHANNEL_INVALID caused by channels.readHistory

Location:
   src/main.rs:108

  ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ BACKTRACE ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
                                ⋮ 10 frames hidden ⋮
  11: <core::result::Result<T,F> as core::ops::try_trait::FromResidual<core::result::Result<core::convert::Infallible,E>>>::from_residual::ha5301abe955d1452
      at /rustc/1409c015b44a4d4d38bef2250b2a37c17b8b7463/library/core/src/result.rs:2005
  12: teler::async_main::{{closure}}::h90fcdfb4b42256fb
      at [: REDACTED :]/src/main.rs:108
  13: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll::hea357f42dab0468d
      at /rustc/1409c015b44a4d4d38bef2250b2a37c17b8b7463/library/core/src/future/mod.rs:84
  14: tokio::park::thread::CachedParkThread::block_on::{{closure}}::hedabe1cf6d3ac414
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/park/thread.rs:263
  15: tokio::coop::with_budget::{{closure}}::hf20fab9d4e2877f1
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/coop.rs:102
  16: std::thread::local::LocalKey<T>::try_with::h39bbd680e2703f24
      at /rustc/1409c015b44a4d4d38bef2250b2a37c17b8b7463/library/std/src/thread/local.rs:412
  17: std::thread::local::LocalKey<T>::with::hd36eead3106eed52
      at /rustc/1409c015b44a4d4d38bef2250b2a37c17b8b7463/library/std/src/thread/local.rs:388
  18: tokio::coop::with_budget::h6ad65d09b57b9671
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/coop.rs:95
  19: tokio::coop::budget::h775bf44d1be1b855
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/coop.rs:72
  20: tokio::park::thread::CachedParkThread::block_on::h067404627065753b
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/park/thread.rs:263
  21: tokio::runtime::enter::Enter::block_on::h46b8121fb0149dc2
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/enter.rs:151
  22: tokio::runtime::thread_pool::ThreadPool::block_on::h6823dce7d6efb021
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/thread_pool/mod.rs:73
  23: tokio::runtime::Runtime::block_on::h389045e104f2fd21
      at [: REDACTED :]/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.17.0/src/runtime/mod.rs:477
  24: teler::main::h35a90554c994d166
      at [: REDACTED :]/src/main.rs:123
  25: core::ops::function::FnOnce::call_once::h0acd5959b25e4710
      at /rustc/1409c015b44a4d4d38bef2250b2a37c17b8b7463/library/core/src/ops/function.rs:227
                                ⋮ 13 frames hidden ⋮

George-Miao avatar Feb 18 '22 13:02 George-Miao

The only thing I can think of is, Telegram may be sending a channel with min = true (in which case its access_hash cannot be used in requests). This means that message should be getting the access hash from the cache and not the channel object itself.

Lonami avatar Feb 18 '22 14:02 Lonami

This is essentially the same as the more general #135 so I'll close it in favor of that.

Lonami avatar Oct 15 '22 08:10 Lonami