Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

client: bg-run failed #731

Open
wind-hx opened this issue Mar 24, 2022 · 3 comments
Open

client: bg-run failed #731

wind-hx opened this issue Mar 24, 2022 · 3 comments
Labels
bug Something isn't working

Comments

@wind-hx
Copy link

wind-hx commented Mar 24, 2022

go version: go version go1.17.2 darwin/amd64
td version: v0.55.2

// Binary bg-run implements alternative to Run pattern.
package main

import (
	"context"
	"fmt"
	"time"

	"go.uber.org/zap"

	"github.com/gotd/contrib/bg"

	"github.com/gotd/td/examples"
	"github.com/gotd/td/telegram"
)

func main() {
	// Some users find explicit client.Run(ctx, f) pattern not very convenient.
	//
	// However, it is possible to implement wrapper and use classic "Connect"
	// pattern instead.
	//
	// The `contrib/bg` package is example implementation of such pattern.
	examples.Run(func(ctx context.Context, log *zap.Logger) error {
		phone := "xxxxxxxx"
		client := telegram.NewClient(123, "xxxxxxxxx", telegram.Options{
			SessionStorage: &telegram.FileSessionStorage{
				Path: phone,
			},
			Logger: log,
		})

		// bg.Connect will call Run in background.
		// Call stop() to disconnect and release resources.
		stop, err := bg.Connect(client)
		if err != nil {
			fmt.Println("Connect err", err)
			return err
		}
		defer func() { _ = stop() }()

		fmt.Println("connect")
		// Now you can use client.
		status, err := client.Auth().Status(ctx)
		if err != nil {
			fmt.Println("Status err", err)
			return err
		}
		fmt.Println(status)
		fmt.Println("done")

		return nil
	})
}

No output Status err
No output done

This is console log

2022-03-24T14:22:27.285+0800    INFO    conn.mtproto.rpc        rpc/engine.go:42        Initialized     {"v": "v0.55.2", "conn_id": 0, "dc_id": 2, "retry_interval": "5s", "max_retries": 5}
connect
2022-03-24T14:22:27.285+0800    INFO    telegram/connect.go:114 Starting        {"v": "v0.55.2"}
2022-03-24T14:22:27.290+0800    INFO    telegram/session.go:46  Connection restored from state  {"v": "v0.55.2", "addr": "", "key_id": "ae4a4a4f6c56f5d1"}
2022-03-24T14:22:27.290+0800    INFO    conn.mtproto.rpc        rpc/engine.go:42        Initialized     {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "retry_interval": "5s", "max_retries": 5}
2022-03-24T14:22:27.291+0800    DEBUG   conn.mtproto    mtproto/conn.go:198     Run: start      {"v": "v0.55.2", "conn_id": 0, "dc_id": 5}
2022-03-24T14:22:27.292+0800    INFO    conn.mtproto    mtproto/connect.go:44   Key already exists      {"v": "v0.55.2", "conn_id": 0, "dc_id": 5}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto    mtproto/connect.go:49   Generating new session id       {"v": "v0.55.2", "conn_id": 0, "dc_id": 5}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.group      tdsync/cancel_group.go:47       Task started    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "task": "readLoop"}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.group      tdsync/cancel_group.go:47       Task started    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "task": "handleClose"}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.group      tdsync/cancel_group.go:47       Task started    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "task": "ackLoop"}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.read       mtproto/read.go:135     Read loop started       {"v": "v0.55.2", "conn_id": 0, "dc_id": 5}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.group      tdsync/cancel_group.go:47       Task started    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "task": "userCallback"}
2022-03-24T14:22:27.292+0800    DEBUG   conn    manager/conn.go:191     Initializing    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.group      tdsync/cancel_group.go:47       Task started    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "task": "pingLoop"}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.group      tdsync/cancel_group.go:47       Task started    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "task": "saltsLoop"}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto    mtproto/rpc.go:29       Invoke start    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "msg_id": 7078548258099032312}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.rpc        rpc/engine.go:87        Do called       {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "msg_id": 7078548258099032312}
2022-03-24T14:22:27.292+0800    DEBUG   conn.mtproto.rpc        rpc/ack.go:34   Waiting for acknowledge {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "ack_id": 7078548258099032312}
2022-03-24T14:22:27.293+0800    DEBUG   conn.mtproto    mtproto/new_encrypted_msg.go:62 Request {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0xbf9459b7", "type_name": "invokeWithoutUpdates#bf9459b7", "msg_id": 7078548258099032312}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto    mtproto/handle_message.go:19    Handle message  {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0xf35c6d01", "type_name": "rpc_result", "size_bytes": 400, "msg_id": 7078548260474077185}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto    mtproto/handle_result.go:24     Handle result   {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0x3072cfa1", "type_name": "gzip", "size_bytes": 388, "msg_id": 7078548258099032312}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto    mtproto/handle_message.go:19    Handle message  {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0x73f1f8dc", "type_name": "message_container", "size_bytes": 88, "msg_id": 7078548260449490945}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto    mtproto/handle_message.go:19    Handle message  {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0x9ec20908", "type_name": "new_session_created#9ec20908", "size_bytes": 28, "msg_id": 7078548260449490945}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto    mtproto/handle_session_created.go:21    Session created {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "unique_id": 7847006222195403137, "first_msg_id": 7078548258099032312, "first_msg_time": "2022-03-24T14:22:27.292+0800"}
2022-03-24T14:22:27.532+0800    INFO    conn.mtproto    mtproto/salt.go:21      Salt updated    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "old": -2559789343209025617, "new": 2679543410608487219}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto    mtproto/new_encrypted_msg.go:62 Request {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0xb921bd04", "type_name": "get_future_salts#b921bd04", "msg_id": 7078548258338813312}
2022-03-24T14:22:27.532+0800    INFO    conn    manager/conn.go:79      SessionInit     {"v": "v0.55.2", "conn_id": 0, "dc_id": 5}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto    mtproto/handle_result.go:39     Decompressed    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0x330b4067", "type_name": "config#330b4067", "size_bytes": 976, "msg_id": 7078548258099032312}
2022-03-24T14:22:27.532+0800    DEBUG   conn.mtproto.rpc        rpc/engine.go:99        Handler called  {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "msg_id": 7078548258099032312}
2022-03-24T14:22:27.533+0800    DEBUG   conn.mtproto    mtproto/rpc.go:47       Invoke end      {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "msg_id": 7078548258099032312}
2022-03-24T14:22:27.533+0800    DEBUG   conn.mtproto.group      tdsync/cancel_group.go:47       Task complete   {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "task": "userCallback", "elapsed": "240.563799ms"}
2022-03-24T14:22:27.533+0800    DEBUG   telegram/connect.go:84  Ready   {"v": "v0.55.2"}
2022-03-24T14:22:27.537+0800    DEBUG   telegram/session.go:89  Data saved      {"v": "v0.55.2", "key_id": "ae4a4a4f6c56f5d1"}
2022-03-24T14:22:27.537+0800    DEBUG   conn.mtproto    mtproto/handle_message.go:19    Handle message  {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0x62d6b459", "type_name": "msgs_ack#62d6b459", "size_bytes": 20, "msg_id": 7078548260449490945}
2022-03-24T14:22:27.537+0800    DEBUG   conn.mtproto    mtproto/handle_ack.go:17        Received ack    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "msg_ids": [7078548258099032312]}
2022-03-24T14:22:27.537+0800    DEBUG   conn.mtproto.rpc        rpc/ack.go:15   Acknowledge callback not set    {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "msg_id": 7078548258099032312}
2022-03-24T14:22:27.661+0800    DEBUG   conn.mtproto    mtproto/handle_message.go:19    Handle message  {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "type_id": "0xae500895", "type_name": "future_salts#ae500895", "size_bytes": 84, "msg_id": 7078548261070615553}
2022-03-24T14:22:27.661+0800    DEBUG   conn.mtproto    mtproto/handle_future_salts.go:23       Got future salts        {"v": "v0.55.2", "conn_id": 0, "dc_id": 5, "server_time": "2022-03-24T14:22:27.000+0800"}

But on the next line "fmt.Println("connect")"
Add "time.Sleep(time.Duration(200) * time.Millisecond)"
everything is ok

@wind-hx wind-hx added the bug Something isn't working label Mar 24, 2022
@wind-hx wind-hx changed the title [client]: bg-run failed client: bg-run failed Mar 24, 2022
@not-a-toad
Copy link

not-a-toad commented Mar 30, 2022

I have same bug :c
But thanks for this

Add "time.Sleep(time.Duration(200) * time.Millisecond)"

@wind-hx
Copy link
Author

wind-hx commented Mar 31, 2022

I have same bug :c But thanks for this

Add "time.Sleep(time.Duration(200) * time.Millisecond)"

It seems to be a bug caused by async connections, I don't know how to fix it, I don't want to solve this problem with sleep

@imjdl
Copy link

imjdl commented Apr 28, 2022

I had the same problem.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants