Catch 420

[Schenn]

When Twitter has rate-limited the app, it responds with error 420. This error is not caught by phirehose and can lead to rate destruction as it attempts to reconnect again and again after having been rate-limited.

[fennb]

Hey there,

Phirehose currently behaves the same on all errors (ie: anything not a HTTP 200/OK) and should continually back-off reconnect attempts until it hits httpBackoffMax (240 seconds).

Is this not the behaviour you are seeing/wanting?

[Schenn]

The reconnect attempts are happening too frequent inside of those two minutes for 420 errors, this ends up eating up the connection rate limit for streams (which take 15 minutes to cool down on Twitter's end) this leaves the app in a state of 420 for an even longer period of time due to the rejected reconnect attempts.

[DarrenCook]

The reconnect attempts are happening too frequent inside of those two minutes...

Sounds strange. Can you record the times of each of the reconnect attempts that you see? That might give a clue where the bug is.

There is no chance you have 2+ instances running? Or 2+ servers connecting using the same account?

Darren

Darren Cook, Software Researcher/Developer My new book: Data Push Apps with HTML5 SSE Published by O'Reilly: (ask me for a discount code!) http://shop.oreilly.com/product/0636920030928.do Also on Amazon and at all good booksellers!

[Schenn]

No, I only have one instance running. Unfortunately, it's really hard to tell if this is the problem because the only error being logged is the Undefined Index error I also reported. This issue seems to occur when twitter is responding with a 420, however, the http code isn't being logged. If I use XDebug and set a breakpoint, then i can get the message out of twitter (that it's 420 and to enhance calm but, if Xdebug is running a second service of the script, that could be the cause of the 420)

However, If I step through with xdebug, sometimes I get a 200 back and on that 200, it's able to parse one or two tweets. When I'm not getting a 200 back, I get the undefined index error.

But, here is the log so far:

[12-May-2015 12:45:06 America/Los_Angeles] PHP Notice: Undefined offset: 2 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:45:06 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:45:06 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:45:06 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:45:06 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:45:06 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:45:06 America/Los_Angeles] PHP Notice: Undefined offset: 1 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:45:06 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:45:06 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:45:06 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:45:06 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:45:06 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:45:06 America/Los_Angeles] Phirehose: HTTP failure 1 of 20 connecting to stream: HTTP ERROR : (). Sleeping for 10 seconds. [12-May-2015 12:45:16 America/Los_Angeles] Phirehose: Connecting to twitter stream: https://stream.twitter.com/1.1/statuses/filter.json with params: array ( 'track' => 'mirakaddoura,thewonderclock,wonderclock', 'follow' => '585866255',) [12-May-2015 12:45:17 America/Los_Angeles] Phirehose: Connecting to ssl://stream.twitter.com, port=443, connectTimeout=5 [12-May-2015 12:45:17 America/Los_Angeles] Phirehose: Connection established to stream.twitter.com [12-May-2015 12:45:17 America/LosAngeles] Phirehose: POST /1.1/statuses/filter.json HTTP/1.1 Host: stream.twitter.com:443 Connection: Close Content-type: application/x-www-form-urlencoded Content-length: 66 Accept: /_ Authorization: OAuth realm="",oauth_consumer_key="PphRdi8Rr40RVoTPKY9IZhIhX",oauth_nonce="59df38ac95753c4c93aa8e0e33fb3e5c",oauth_signature_method="HMAC-SHA1",oauth_timestamp="1431459917",oauth_version="1.0A",oauth_token="585866255-gqrhwljiPXt1spNWsc2vnOexUTeAykHBEv2NkYH0",oauth_signature="qCkHM7DxVhv7zg8mDwa9Z9qFhkQ%3D" User-Agent: Phirehose/1.0RC +https://github.com/fennb/phirehose

track=mirakaddoura%2Cthewonderclock%2Cwonderclock&follow=585866255

[12-May-2015 12:45:17 America/Los_Angeles] PHP Notice: Undefined offset: 2 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:45:17 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:45:17 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:45:17 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:45:17 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:45:17 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:45:17 America/Los_Angeles] PHP Notice: Undefined offset: 1 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:45:17 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:45:17 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:45:17 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:45:17 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:45:17 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:45:17 America/Los_Angeles] Phirehose: HTTP failure 2 of 20 connecting to stream: HTTP ERROR : (). Sleeping for 20 seconds. [12-May-2015 12:45:37 America/Los_Angeles] Phirehose: Connecting to twitter stream: https://stream.twitter.com/1.1/statuses/filter.json with params: array ( 'track' => 'mirakaddoura,thewonderclock,wonderclock', 'follow' => '585866255',) [12-May-2015 12:45:37 America/Los_Angeles] Phirehose: Connecting to ssl://stream.twitter.com, port=443, connectTimeout=5 [12-May-2015 12:45:37 America/Los_Angeles] Phirehose: Connection established to stream.twitter.com [12-May-2015 12:45:37 America/LosAngeles] Phirehose: POST /1.1/statuses/filter.json HTTP/1.1 Host: stream.twitter.com:443 Connection: Close Content-type: application/x-www-form-urlencoded Content-length: 66 Accept: /_ Authorization: OAuth realm="",oauth_consumer_key="PphRdi8Rr40RVoTPKY9IZhIhX",oauth_nonce="c628e9436242b4e0f8c88f6aaee22811",oauth_signature_method="HMAC-SHA1",oauth_timestamp="1431459937",oauth_version="1.0A",oauth_token="585866255-gqrhwljiPXt1spNWsc2vnOexUTeAykHBEv2NkYH0",oauth_signature="9Hsn0GBtWuohuCsLU24eMozpckE%3D" User-Agent: Phirehose/1.0RC +https://github.com/fennb/phirehose

track=mirakaddoura%2Cthewonderclock%2Cwonderclock&follow=585866255

[12-May-2015 12:45:37 America/Los_Angeles] PHP Notice: Undefined offset: 2 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:45:37 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:45:37 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:45:37 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:45:37 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:45:37 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:45:37 America/Los_Angeles] PHP Notice: Undefined offset: 1 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:45:37 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:45:37 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:45:37 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:45:37 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:45:37 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:45:37 America/Los_Angeles] Phirehose: HTTP failure 3 of 20 connecting to stream: HTTP ERROR : (). Sleeping for 40 seconds. [12-May-2015 12:46:17 America/Los_Angeles] Phirehose: Connecting to twitter stream: https://stream.twitter.com/1.1/statuses/filter.json with params: array ( 'track' => 'mirakaddoura,thewonderclock,wonderclock', 'follow' => '585866255',) [12-May-2015 12:46:17 America/Los_Angeles] Phirehose: Connecting to ssl://stream.twitter.com, port=443, connectTimeout=5 [12-May-2015 12:46:17 America/Los_Angeles] Phirehose: Connection established to stream.twitter.com [12-May-2015 12:46:17 America/LosAngeles] Phirehose: POST /1.1/statuses/filter.json HTTP/1.1 Host: stream.twitter.com:443 Connection: Close Content-type: application/x-www-form-urlencoded Content-length: 66 Accept: /_ Authorization: OAuth realm="",oauth_consumer_key="PphRdi8Rr40RVoTPKY9IZhIhX",oauth_nonce="86150ff8a5102bb0466050dec9a0c8bc",oauth_signature_method="HMAC-SHA1",oauth_timestamp="1431459977",oauth_version="1.0A",oauth_token="585866255-gqrhwljiPXt1spNWsc2vnOexUTeAykHBEv2NkYH0",oauth_signature="EKNZ%2BDFPX8TLDBeaj3WyPeET%2F%2Fw%3D" User-Agent: Phirehose/1.0RC +https://github.com/fennb/phirehose

track=mirakaddoura%2Cthewonderclock%2Cwonderclock&follow=585866255

[12-May-2015 12:46:17 America/Los_Angeles] PHP Notice: Undefined offset: 2 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:46:17 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:46:17 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:46:17 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:46:17 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:46:17 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:46:17 America/Los_Angeles] PHP Notice: Undefined offset: 1 in C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php on line 689 [12-May-2015 12:46:17 America/Los_Angeles] PHP Stack trace: [12-May-2015 12:46:17 America/Los_Angeles] PHP 1. {main}() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:0 [12-May-2015 12:46:17 America/Los_Angeles] PHP 2. Phirehose->consume() C:\xampp\htdocs\wonderclock\twitterminer\db\get_tweets.php:63 [12-May-2015 12:46:17 America/Los_Angeles] PHP 3. Phirehose->reconnect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:411 [12-May-2015 12:46:17 America/Los_Angeles] PHP 4. Phirehose->connect() C:\xampp\htdocs\wonderclock\vendor\fennb\phirehose\lib\Phirehose.php:824 [12-May-2015 12:46:17 America/Los_Angeles] Phirehose: HTTP failure 4 of 20 connecting to stream: HTTP ERROR : (). Sleeping for 80 seconds.

[Schenn]

The log says line 689 instead of 688 because I tried to move the fgets above the preg_replace in an attempt to nail down a more specific reason for the error.

When this error occurs, I don't get any tweets from the user I've marked, however as I said above, when I step through with XDebug and get a 400, I get the tweets until I stop stepping through and the undefined indexes begin again.

[DarrenCook]

The log says line 689 instead of 688

https://github.com/fennb/phirehose/blob/master/lib/Phirehose.php#L689

because I tried to move the fgets above the preg_replace in an attempt to nail down a more specific reason for the error.

That's exactly what I wanted to know. I.e. change line 689 to be:

$firstLine = fgets($this->conn, 1024); $firstLineParts = preg_split('/\s+/', trim($firstLine) ); if(count($firstLineParts)!=3){ $this->log('BAD firstLine="'.$firstLine.'"'); $connectFailures++; $httpRetry = ($httpRetry < $this->httpBackoffMax) ? $httpRetry * 2 : $this->httpBackoffMax; sleep($httpRetry); continue; } list($httpVer, $httpCode, $httpMessage) = $firstLineParts;

(untested, but I think that makes a reasonable patch, as it does not remove or alter any existing functionality.)

Darren

[Schenn]

Now it's saying undefined variable httpCode line: 745

[DarrenCook]

But what was the value of firstLine in the log() (assuming you did the above patch)? (I just fixed a typo in it, by the way)

[Schenn]

Bad firstLine = ""

[DarrenCook]

Bad firstLine = ""

Perhaps you could write a hack to get the next line if it reads a blank line, and let us know how it goes? I.e. if the next line contains the header we were expecting, then that is a fix. (I'd have to go back and read the http protocol, but perhaps a blank line is even valid at this point??)

...still doesn't explain why only you are seeing this. Are you connecting through a proxy? Or anything else you can think of that is unusual? (Twitter have been known to introduce new server software gradually, with little or no warning, so it is not impossible this is something new that will affect everyone in the next week...)

Darren

[Schenn]

Hmm, I'll give that a try and see if I can get some more information out of it.

In the meantime, twitter's streaming api says this about blank lines: Blank lines On slow streams, some messages may be blank lines which serve as “keep-alive” signals to prevent clients and other network infrastructure from assuming the stream has stalled and closing the connection.

[Schenn]

Also, no proxy connections or anything like that. Just a regular hook-up to broadband through a wireless router. Windows 8.1. Using command to run the script.

[fennb]

Regarding reconnects, it does indeed appear that Twitter has updated recommendations regarding reconnections:

• Back off linearly for TCP/IP level network errors. These problems are generally temporary and tend to clear quickly. Increase the delay in reconnects by 250ms each attempt, up to 16 seconds.
• Back off exponentially for HTTP errors for which reconnecting would be appropriate. Start with a 5 second wait, doubling each attempt, up to 320 seconds.
• Back off exponentially for HTTP 420 errors. Start with a 1 minute wait and double each attempt. Note that every HTTP 420 received increases the time you must wait until rate limiting will no longer will be in effect for your account.

Based on that, you're absolutely right @Schenn, Phirehose should respond slightly differently for 420 errors and back off more quickly.

[enkeli]

I'm having the same issue. Any solution yet?