[BUG]: Logger Syslog - empty line on output

[zordon13]

Describe the bug
One write one line to syslog logger, in journalctl have two line. Second line is empty.

To Reproduce

Provide output if related. Provide coredump if any. Use https://docs.phalcon.io/en/latest/generating-backtrace as reference.

Steps to reproduce the behavior:

use Phalcon\Logger;
use Phalcon\Logger\Adapter\Syslog;

// Setting ident/mode/facility
$adapter = new Syslog(
    'ident-name',
    [
        'option'   => LOG_NDELAY,
        'facility' => LOG_MAIL,
    ]
);

$logger  = new Logger(
    'messages',
    [
        'main' => $adapter,
    ]
);

$logger->error('Something went wrong');

Two line in journalctl. Second is empty.

ноя 18 16:02:36 ipc ident-name[26615]: [Mon, 18 Nov 19 16:02:36 +0300][error] Something went wrong
ноя 18 16:02:36 ipc ident-name[26615]:

Expected behavior

ноя 18 16:02:36 ipc ident-name[26615]: [Mon, 18 Nov 19 16:02:36 +0300][error] Something went wrong

Example 2

for($i = 0; $i < 3; $i++) {
    $logger->debug('Line: '.$i);
}

ноя 18 16:15:24 ipc ident-name[28461]: [Mon, 18 Nov 19 16:15:24 +0300][debug] Line: 0
ноя 18 16:15:24 ipc ident-name[28461]: 
ноя 18 16:15:24 ipc ident-name[28461]: [Mon, 18 Nov 19 16:15:24 +0300][debug] Line: 1
ноя 18 16:15:24 ipc ident-name[28461]: 
ноя 18 16:15:24 ipc ident-name[28461]: [Mon, 18 Nov 19 16:15:24 +0300][debug] Line: 2
ноя 18 16:15:24 ipc ident-name[28461]: 

Screenshots

If applicable, add screenshots to help explain your problem.

Details

• Phalcon version: (php --ri phalcon)

Web framework delivered as a C-extension for PHP
phalcon => enabled
Author => Phalcon Team and contributors
Version => 4.0.0-rc.3
Build Date => Nov 17 2019 19:42:14
Powered by Zephir => Version 0.12.10-fedc314

Directive => Local Value => Master Value
phalcon.db.escape_identifiers => On => On
phalcon.db.force_casting => Off => Off
phalcon.orm.case_insensitive_column_map => Off => Off
phalcon.orm.cast_last_insert_id_to_int => Off => Off
phalcon.orm.cast_on_hydrate => Off => Off
phalcon.orm.column_renaming => On => On
phalcon.orm.disable_assign_setters => Off => Off
phalcon.orm.enable_implicit_joins => On => On
phalcon.orm.enable_literals => On => On
phalcon.orm.events => On => On
phalcon.orm.exception_on_failed_save => Off => Off
phalcon.orm.exception_on_failed_metadata_save => On => On
phalcon.orm.ignore_unknown_columns => Off => Off
phalcon.orm.late_state_binding => Off => Off
phalcon.orm.not_null_validations => On => On
phalcon.orm.update_snapshot_on_save => On => On
phalcon.orm.virtual_foreign_keys => On => On
phalcon.warning.enable => On => On

• PHP Version: (php -v)

PHP 7.3.11 (cli) (built: Oct 26 2019 15:16:52) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.3.11, Copyright (c) 1998-2018 Zend Technologies
    with Zend OPcache v7.3.11, Copyright (c) 1999-2018, by Zend Technologies
    with Xdebug v2.8.0, Copyright (c) 2002-2019, by Derick Rethans

• Operating System:

Linux ipc 5.3.11-gentoo #1 SMP Sun Nov 17 10:27:19 MSK 2019 x86_64 AMD Ryzen 5 2600 Six-Core Processor AuthenticAMD GNU/Linux

emerge --info
Portage 2.3.79 (python 3.6.9-final-0, default/linux/amd64/17.0/desktop/plasma/systemd, gcc-9.2.0, glibc-2.30-r2, 5.3.11-gentoo x86_64)
=================================================================
System uname: Linux-5.3.11-gentoo-x86_64-AMD_Ryzen_5_2600_Six-Core_Processor-with-gentoo-2.6
KiB Mem:    16386372 total,   4741124 free
KiB Swap:          0 total,         0 free
Timestamp of repository gentoo: Mon, 18 Nov 2019 07:30:01 +0000
Head commit of repository gentoo: a97c31f57e78aadff185b0862e55bc24540d6354
sh bash 5.0_p11
ld GNU ld (Gentoo 2.32 p2) 2.32.0
app-shells/bash:          5.0_p11::gentoo
dev-java/java-config:     2.2.0-r4::gentoo
dev-lang/perl:            5.30.1::gentoo
dev-lang/python:          2.7.17::gentoo, 3.6.9::gentoo, 3.7.5-r1::gentoo, 3.8.0::gentoo
dev-util/cmake:           3.15.5::gentoo
dev-util/pkgconfig:       0.29.2::gentoo
sys-apps/baselayout:      2.6-r1::gentoo
sys-apps/sandbox:         2.18::gentoo
sys-devel/autoconf:       2.13-r1::gentoo, 2.69-r4::gentoo
sys-devel/automake:       1.13.4-r2::gentoo, 1.15.1-r2::gentoo, 1.16.1-r2::gentoo
sys-devel/binutils:       2.30-r4::gentoo, 2.31.1-r4::gentoo, 2.32-r1::gentoo, 2.33.1::gentoo
sys-devel/gcc:            8.2.0-r6::gentoo, 8.3.0-r1::gentoo, 9.1.0-r1::gentoo, 9.2.0-r2::gentoo
sys-devel/gcc-config:     2.1::gentoo
sys-devel/libtool:        2.4.6-r5::gentoo
sys-devel/make:           4.2.1-r4::gentoo
sys-kernel/linux-headers: 5.3-r1::gentoo (virtual/os-headers)
sys-libs/glibc:           2.30-r2::gentoo

• Installation type: Compiling from source || installing via package manager
  source
• Server: Nginx | Apache | Other

nginx -v
nginx version: nginx/1.17.5

Additional context
This behavior appeared in version 4.0.0-rc.3

[ruudboon]

Thnx for reporting! I can confirm this under macOS

[niden]

@zordon13 thanks for reporting this. Sadly syslog tests are difficult so we did not find this earlier. The issue came from the Line formatter which automatically added a PHP_EOL at the end of the message and this is why you saw the new line in your syslog.

I have moved the PHP_EOL in the Stream adapter so that fixes it.

[niden]

Resolved in #14548

[niden]

Thank you @zordon13

[zordon13]

Thank you @zordon13

Thank you for fast fix. Waiting release.

[zordon13]

The problem reappeared in the version 5.* (cphalcon-5.0.0beta2 for example)

use Phalcon\Logger\Logger;
use Phalcon\Logger\Adapter\Syslog;

// Setting ident/mode/facility
$adapter = new Syslog(
    'ident-name',
    [
        'option'   => LOG_NDELAY,
        'facility' => LOG_MAIL,
    ]
);

$logger  = new Logger(
    'messages',
    [
        'main' => $adapter,
    ]
);

$logger->error('Something went wrong');

for($i = 0; $i < 3; $i++) {
    $logger->debug('Line: '.$i);
}

янв 06 16:03:13 host ident-name[4617]: [2022-01-06T16:03:13+03:00][ERROR] Something went wrong
янв 06 16:03:13 host ident-name[4617]:
янв 06 16:03:13 host ident-name[4617]: [2022-01-06T16:03:13+03:00][DEBUG] Line: 0
янв 06 16:03:13 host ident-name[4617]:
янв 06 16:03:13 host ident-name[4617]: [2022-01-06T16:03:13+03:00][DEBUG] Line: 1
янв 06 16:03:13 host ident-name[4617]:
янв 06 16:03:13 host ident-name[4617]: [2022-01-06T16:03:13+03:00][DEBUG] Line: 2
янв 06 16:03:13 host ident-name[4617]:

[niden]

Resolved in #15858

Thank you @zordon13 for finding this.