How can i get microseconds with Logger?

i can calculate the microseconds with this

( microtime(true) - time() ) * 1000

but how do i get it into the logger at the "correct" place, so i get it like

[13:51:10.7347]

i thought, i got it, but the following code did not work because i only get access to the %message%-part.

i wanted to replace "%micro%" with the microseconds

$Logger = new \Phalcon\Logger\Adapter\File($fileName);
$logFormater = new \Phalcon\Logger\Formatter\Line;
$logFormater->setFormat('[%date%.%micro%][%type%] %message%');
$logFormater->setDateFormat('H:i:s.u');
$Logger->setFormatter($logFormater);
...
$message = str_replace('%micro%', (time() - microtime(true)) * 1000, $message);
$Logger->log($message, $priority);

Doesn't look like you can override this one :-/

If you have a look at the source code at https://github.com/phalcon/cphalcon/blob/master/ext/logger/formatter/line.c you see that the function phalcon_date is called with a date, a date format and a timestamp.

PHALCON_INIT_VAR(date);
phalcon_date(date, date_format, timestamp TSRMLS_CC);

That function is in string.c in the kernel: https://github.com/phalcon/cphalcon/blob/master/ext/kernel/string.c

void phalcon_date(zval *return_value, zval *format, zval *timestamp TSRMLS_DC)
{
    long int ts;
    zval copy;
    int use_copy = 0;
    char *formatted;
    if (unlikely(Z_TYPE_P(format) != IS_STRING)) {
        zend_make_printable_zval(format, &copy, &use_copy);
        if (use_copy) {
            format = ©
        }
    }
    ts = (timestamp) ? phalcon_get_intval(timestamp) : time(NULL);
    formatted = php_format_date(Z_STRVAL_P(format), Z_STRLEN_P(format), ts, 1 TSRMLS_CC);
    ZVAL_STRING(return_value, formatted, 0);
    if (unlikely(use_copy)) {
        zval_dtor(&copy);
    }
}

It's the phalcon_get_intval function that is responsible for returning you the timestamp. Unfortunately I cannot find where the php_format_date function is defined (can't find the ext/date/php_date.c file), which is the one that prints out the string to your log. But then still, I see no possibility to override the timestamp formatting. You could write it yourself or submit a feature request.

Best regards, Sven

BTW: how do you format an answer here to get those nice black backgrounds?

@sventunus Hi, i use three backticks followed by text "php".

Replace the following singlequotes with: `

'''php

your-code-here

'''

There was a markdown help, but the link is suddenly dead. https://forum.phalcon.io/help/markdown

Swen

Cool, thanks Swen! :)

i solved it with a separate class which inherits from \Phalcon\Logger\Formatter\Line

class LogFormatter extends \Phalcon\Logger\Formatter\Line {

    public function format($message, $type, $timestamp, $context ) {

        $dateTime = new \DateTime;
        $dateTime->setTimestamp($timestamp);
        $dateFormat = str_replace('u', floor((microtime(true) - $timestamp) * 1000), $this->getDateFormat());

        $formated = str_replace('%date%', $dateTime->format( $dateFormat ), $this->getFormat() );
        $formated = str_replace('%message%', $message, $formated);
        return str_replace('%type%', $this->getTypeString($type), $formated) . "\n";
    }
}

Strange thing is, that toward the php documentation DateTime::format() does not give me the micreconds! So i made a workaraound.

All in all it works fine for me.

Nice fix! Did some deeper digging too BTW, and that php_format_date function is just in PHP's source code: https://github.com/php/php-src/blob/d0cb715373c3fbe9dc095378ec5ed8c71f799f67/ext/date/php_date.h

So nothing wrong with the Phalcon code, it should just work if you pass in the correct format. That means you have probably discovered a bug in PHP :-) Will look into it more, am fascinated by your discovery.

It is a bug indeed (well, a feature request maybe), and an old one too! Check https://bugs.php.net/bug.php?id=49779