ChimeraCoder / anaconda

A Go client library for the Twitter 1.1 API
MIT License
1.14k stars 247 forks source link

UserStream: many "twitter socket closed, leaving loop" until error 420 #231

Open elias19r opened 6 years ago

elias19r commented 6 years ago

From logger, I see it keeps getting "twitter socket closed, leaving loop" and then trying to reconnect until it receives a 420 error from Twittter and backs off for a while.

2018/02/08 21:55:08 Response status=200 OK code=200
2018/02/08 21:55:08 Listening to twitter socket
2018/02/08 21:55:08 twitter socket closed, leaving loop
... [many times] ...
2018/02/08 21:55:17 Response status=420 Enhance Your Calm code=420
2018/02/08 21:55:17 Twitter streaming: backing off as got : 420 Enhance Your Calm
^Csignal: interrupt

As far as I understand from the code, scanner.Scan() is returning false at https://github.com/ChimeraCoder/anaconda/blob/6d66c395d5c8e63b38413965c43155fc2947a901/streaming.go#L176

Is it Twitter blocking User Stream access for my account?

Testing code:

package main

import (
    "fmt"
    "github.com/ChimeraCoder/anaconda"
    "net/url"
)

func main() {
    anaconda.SetConsumerKey("YOUR_CONSUMER_KEY")
    anaconda.SetConsumerSecret("YOUR_CONSUMER_SECRET")

    api := anaconda.NewTwitterApi("YOUR_ACCESS_TOKEN", "YOUR_ACCESS_TOKEN_SECRET")
    api.SetLogger(anaconda.BasicLogger)
    stream := api.UserStream(url.Values{})

    for {
        item := <-stream.C
        fmt.Println(item)
    }
}
elias19r commented 6 years ago

By adding

if err := scanner.Err(); err != nil {
    s.api.Log.Notice(err)
}

after the mentioned for-loop over scanner.Scan(), I get:

2018/02/09 12:24:18 bufio.Scanner: token too long

So I doubled the scanner buffer size and then it started printing my UserStream data on screen:

scanner := bufio.NewScanner(response.Body)
scanner.Buffer([]byte{}, 2*bufio.MaxScanTokenSize)

I probably should have used url.Values{} params to filter my UserStream because I was getting too large data to fit in scanner buffer.

Or is it a bug?

ChimeraCoder commented 6 years ago

What's the token that it's choking on? I'm surprised that there's a token longer than 64 * 1024 bytes.

elias19r commented 6 years ago

At the moment, the very first token I receive from Twitter is a large array of IDs with 78467 bytes. Printing a reflect.TypeOf() shows it is anaconda.FriendsList type.

UserStream will be replaced in June, so documentation is not clear: https://developer.twitter.com/en/docs/accounts-and-users/subscribe-account-activity/api-reference/user-stream

But looking at "stringify_friend_ids" parameter, it seems that Twitter sends a preamble array of integers with friends IDs upon connecting to UserStream.

rusenask commented 6 years ago

After updating to the most recent version I started getting these as well:

level=info msg="twitter socket closed, leaving loop"
level=info msg="Listening to twitter socket"

In my case I am just using PublicStreamFilter and processing tweets. After some time Twitter removes my access token from the app and then I get 401 :)

Update: After checking out to 6d66c395d5c8e63b38413965c43155fc2947a901 problem seems to go away.

kevflynn commented 6 years ago

👍 on this - i'm getting those same info messages until finally it culminates into

ERRO[1420] Cannot request stream : Post https://stream.twitter.com/1.1/statuses/filter.json: net/http: request canceled (Client.Timeout exceeded while awaiting headers)

That's an error being thrown from a different library, but I have a feeling it's a result of this open/close loop? I tried setting: api.EnableThrottling(30*time.Second, 4) api.SetDelay(30 * time.Second)

But that did not work

kevflynn commented 6 years ago

Looks like it's related to this commit:

https://github.com/ChimeraCoder/anaconda/commit/c0624fed14f17cab6525039cc4a9a0a4e5b48c13

I wonder if the timeout and reconnecting is too aggressive?

According to twitter docs:

The Streaming API will send a keep-alive newline every 30 seconds to prevent your application from timing out the connection. You should wait at least 3 cycles to prevent spurious reconnects in the event of network congestion, local CPU starvation, local GC pauses, etc.

https://developer.twitter.com/en/docs/tweets/filter-realtime/guides/connecting

jimfenton commented 6 years ago

Agreed; this seems to be a regression from c0624fe.

For whatever reason, the keep-alives aren't satisfying the timeout either. I changed the timeout from 20 to 90 seconds and it's still timing out after 90 seconds. For me it's just reconnecting (so harmless?) but maybe I'm just not waiting long enough to get the 420 error.

If you're not subject to the mutex deadlock, it might make sense to comment out twitter.c line 130. This is probably just affecting the streaming API, which Twitter plans to sunset on June 19, 2018, so it may not be worth a long-term fix.

dijit commented 5 years ago

Hi, I'm experiencing similar behaviours.

I've tried listening for all incoming events to see if twitter sends a keep alive or not, but it doesn't seem to. Maybe it's not responding to anacondas keepalive requests?

dijit commented 5 years ago

I just received and email stating these API's they may have been shut down, however, that does not seem to be the case.

This seems to work today; with the caveat that it gets disconnected often; however I do see new tweets being created.

func main() {
        api := anaconda.NewTwitterApiWithCredentials(
        access_token,
        access_token_secret,
        consumer_key,
        consumer_secret,
    )
    log := &logger{logrus.New()}
    log.SetLevel(logrus.DebugLevel)
    api.SetLogger(log)

    v := url.Values{}
    s := api.PublicStreamFilter(v)

    v.Add("follow", "15209123") // 15209123 = @dijit

    for {
        item := <-s.C
        log.Infoln(item)
    }
jimfenton commented 5 years ago

That's interesting -- I had also thought all streaming APIs were shut down in favor of the Account Activity API, but that seems not to be the case for PublicStreamFilter, unlike UserStreams and SiteStreams that were sunset on August 23.

My experience with UserStreams before they were sunset was that they were also closed often by Twitter, which is why the loop method in streaming.go loops and makes a new request when that happens.

0xTHMS commented 5 years ago

Is this still not fixed ?

INFO[0120] twitter socket closed, leaving loop          
ERRO[0120] Cannot request stream : Post https://stream.twitter.com/1.1/statuses/filter.json: write on closed buffer 

After the "write on closed buffer" my program crashes.

All it does is reading from the Stream and printing the values.

I get many "twitter socket closed, leaving loop", but the loop is started again after that. How can I get a similar behavior after the "write on closed buffer" error ?

0xTHMS commented 5 years ago

No support ?

jimfenton commented 5 years ago

I think this is probably due to last August's sunset of the streaming API (or much of it, anyway).

I did some work on an extension (#261) for the account Activity API, but it doesn't have equivalent functionality to the streaming API (in particular, you can't subscribe to a user's "home tweetstream", so I have lost interest in doing more work on this.

0xTHMS commented 5 years ago

Alright, thank you.