swoole-src icon indicating copy to clipboard operation
swoole-src copied to clipboard

Lines to stderr gets tangled

Open firecow opened this issue 1 year ago • 0 comments

Please answer these questions before submitting your issue.

  1. What did you do? If possible, provide a simple script for reproducing the error.
  • We noticed that some logs from our swoole applications couldn't be found in our observability solution, and started digging.
  • We found that swoole somehow doesn't control the flow of logs from workers, when put under pressure.
<?php


$http = new Swoole\Http\Server('0.0.0.0', 9501);

$http->on('Request', function ($request, $response) {
    $response->header('Content-Type', 'text/html; charset=utf-8');
    // Generate a unique string that is the same for each request, but can be used to check integrity of logs with high length
    $word = '';
    $alphabet = 'abcdefghijklmnopqrstuvwxyz';

    // Number to repeat
    $numberToRepeat = 160;

    // Add each letter x times
    foreach (str_split($alphabet) as $letter) {
        $word .= str_repeat($letter, $numberToRepeat);
    }
    $response->end($word);
    fputs(STDERR,  $word . PHP_EOL);
});

$http->set([
    'worker_num' => 64,
]);

$http->start();
php index.php 2>&1 | grep -v -E "a+b+c+d+e+f+g+h+i+j+k+l+m+n+o+p+q+r+s+t+u+v+w+x+y+z+"
wrk -d5m -c10 -t1 http://localhost:9501
  1. What did you expect to see?
  • I expected to see each log line from each worker on a line of its own.
  • This issue makes it impossible for a wide array of log collectors, (promtail, fluentd, filebeat etc.) to collect the logs and ship them to observability solutions
  1. What did you see instead?
  • I see log lines printed inside each other, tangled
  1. What version of Swoole are you using (show your php --ri swoole)?
swoole

Swoole => enabled
Author => Swoole Team <[email protected]>
Version => 5.1.3
Built => Jun 11 2024 16:03:31
coroutine => enabled with boost asm context
epoll => enabled
eventfd => enabled
signalfd => enabled
cpu_affinity => enabled
spinlock => enabled
rwlock => enabled
http2 => enabled
json => enabled
zlib => 1.2.11
mutex_timedlock => enabled
pthread_barrier => enabled
futex => enabled
async_redis => enabled

Directive => Local Value => Master Value
swoole.enable_coroutine => On => On
swoole.enable_library => On => On
swoole.enable_fiber_mock => Off => Off
swoole.enable_preemptive_scheduler => Off => Off
swoole.display_errors => On => On
swoole.use_shortname => On => On
swoole.unixsock_buffer_size => 8388608 => 8388608
  1. What is your machine environment used (show your uname -a & php -v & gcc -v) ?
Linux mjn-laptop 6.5.0-35-generic #35~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Tue May  7 09:00:52 UTC 2 x86_64 x86_64 x86_64 GNU/Linux
Using built-in specs.
COLLECT_GCC=gcc
COLLECT_LTO_WRAPPER=/usr/lib/gcc/x86_64-linux-gnu/11/lto-wrapper
OFFLOAD_TARGET_NAMES=nvptx-none:amdgcn-amdhsa
OFFLOAD_TARGET_DEFAULT=1
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Ubuntu 11.4.0-1ubuntu1~22.04' --with-bugurl=file:///usr/share/doc/gcc-11/README.Bugs --enable-languages=c,ada,c++,go,brig,d,fortran,objc,obj-c++,m2 --prefix=/usr --with-gcc-major-version-only --program-suffix=-11 --program-prefix=x86_64-linux-gnu- --enable-shared --enable-linker-build-id --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --libdir=/usr/lib --enable-nls --enable-bootstrap --enable-clocale=gnu --enable-libstdcxx-debug --enable-libstdcxx-time=yes --with-default-libstdcxx-abi=new --enable-gnu-unique-object --disable-vtable-verify --enable-plugin --enable-default-pie --with-system-zlib --enable-libphobos-checking=release --with-target-system-zlib=auto --enable-objc-gc=auto --enable-multiarch --disable-werror --enable-cet --with-arch-32=i686 --with-abi=m64 --with-multilib-list=m32,m64,mx32 --enable-multilib --with-tune=generic --enable-offload-targets=nvptx-none=/build/gcc-11-XeT9lY/gcc-11-11.4.0/debian/tmp-nvptx/usr,amdgcn-amdhsa=/build/gcc-11-XeT9lY/gcc-11-11.4.0/debian/tmp-gcn/usr --without-cuda-driver --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu --with-build-config=bootstrap-lto-lean --enable-link-serialization=2
Thread model: posix
Supported LTO compression algorithms: zlib zstd
gcc version 11.4.0 (Ubuntu 11.4.0-1ubuntu1~22.04) 
PHP 8.1.2-1ubuntu2.17 (cli) (built: May  1 2024 10:10:07) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.1.2, Copyright (c) Zend Technologies
    with Zend OPcache v8.1.2-1ubuntu2.17, Copyright (c), by Zend Technologies

I also tested with 8.2.20 and 8.3.8, and the behavior is the same.

mod_php and php-fpm have no problems, printing this many logs from multiple workers controlled by a main process.

firecow avatar Jun 11 '24 14:06 firecow