fluent-logger-php This Runs Slower than just running cURL to post logs to the HTTP Listener

Benchmarking on 50 users with a 100 loop count, I get far worse results using this vs cURL. Whereas cURL consistently gives me response times of around 10ms total load time per page on a page where not much is happening, using fluent-logger-php instead immediately increases average load times to about 600ms (all goes well with 10ms response times until about the 200th sample, at which point response times erratically grow into the thousands of ms. I'm guessing this is a buffering issue?

Sep 07 '12 23:09 EliFinkelshteyn

sorry for late response.

(all goes well with 10ms response times until about the 200th sample, at which point response times erratically grow into the thousands of ms. I'm guessing this is a buffering issue?

did you use Fluent\Logger\FluentLogger right? It will sleep thousand of ms when the socket can't write / read correctly. so this is not buffering issue i think.

https://github.com/fluent/fluent-logger-php/blob/master/src/Fluent/Logger/FluentLogger.php#L372

we are finding better way to handle socket on this project as PHP's socket has many limitations. please let me us if you have a good idea. thanks

Sep 10 '12 12:09 chobie

Yeah, that's definitely what it is. It must be failing and sleeping for 1000ms before retrying. I'll roll it out as is onto a production server and a/b test to see how often that happens in the real world. My feeling is most people logging have at least two separate use cases for logging: business critical and not business critical. If it's the former, sleeping 1000ms and trying again makes sense. If it's the latter, I'd think it makes more sense to just drop that log and keep going to keep things fast. Would it make sense to make this a startup option? Maybe something like:

self::$_fluentLogger = new FluentLogger(array("host" => "localhost","port" => "24224", "retry_socket"=>1);

Sep 10 '12 21:09 EliFinkelshteyn

you are right. I'd like to support that use case. for now I added retry_socket option to above branch. but it might change the option key.

I'll test this and merge in this weekend.

Sep 16 '12 05:09 chobie

Sweet, thanks! Let me know if I can help.

Sep 19 '12 00:09 EliFinkelshteyn

@EliFinkelshteyn btw, can you tell me your fluentd structure (send messages to local fluentd or remote fluentd directly) and distribution? I'd like to improve error handling regarding this issue so I'm taking a look about PHP's fwrite implementation.

Sep 24 '12 15:09 chobie

@chobie could you merge the above change to master?

Apr 01 '13 21:04 kzk

@kzk thanks pointing it. i'll test this today.

Apr 01 '13 23:04 chobie

I tried fluent-logger-php with follwing simple code:

<?php
// you can choose your own AutoLoader
require_once __DIR__.'/src/Fluent/Autoloader.php';

use Fluent\Logger\FluentLogger;

Fluent\Autoloader::register();

$logger = new FluentLogger("localhost","24224");

$t = microtime(true);

for ($i = 0; $i < 100000; ++$i) {
    $logger->post("debug.test",array("hello"=>"world"));
}

echo (microtime(true) - $t)

?>

The result of each loops:

10,000 loops: 0.15141582489014 sec 20,000 loops: 1.0778098106384 sec 100,000 loops: 23.173148870468 sec

20000 and 100000 took toooo long time without errors. What is the problem?

Apr 02 '13 08:04 repeatedly

Sorry, this is the my local fluentd configuration mistake...orz

Apr 02 '13 08:04 repeatedly

I merged some commits from retry_socket_opt branch and I'll check that behavior today (if I keep my guts. hehe)

Apr 02 '13 20:04 chobie