TIP: Use Markdown or, <pre> for multi line code blocks / <code> for inline code.
These forums are read-only and for archival purposes only!
Please join our new forums at discourse.kohanaframework.org
Kohana 3.3 strtr "Array to string conversion" issue in Kohana_Log_Writer
  • I would make this and my other issue (http://forum.kohanaframework.org/discussion/11545/possible-bug-with-http_exception-405-in-3-3) a ticket in Kohana's bug tracker but it's not sending me my confirmation email so I'll just hope someone can do it for me.

    The issue is here: https://github.com/kohana/core/blob/3.3/master/classes/Kohana/Log/Writer.php#L81

    I'm not sure what apache/php configuration causes strtr() to be this strict. I'm using PHP 5.4.12-1~precise+1. The $message array passed to this method contains 2 keys which have arrays as values; "additional" and "trace". This causes strtr to throw a "Array to string conversion" error. What made this especially difficult to notice is that the response returns as normal but the status is still a 500. An easier way to see that there is a problem is to look at a 404 page. It's also worth noting that this error does not get thrown on my local Lion install of PHP 5.4.11.

    This is probably a result of this fix: https://bugs.php.net/bug.php?id=63893

    I implemented this quick fix to get things working again:

    public function format_message(array $message, $format = "time --- level: body in file:line")
    {
       $additional = isset($message['additional']['exception']) ? $message['additional']['exception'] : null;
       $message['time'] = Date::formatted_time('@'.$message['time'], Log_Writer::$timestamp, Log_Writer::$timezone, TRUE);
       $message['level'] = $this->_log_levels[$message['level']];
       unset($message['additional']);
       unset($message['trace']);
    
       $string = strtr($format, $message);
    
       if ($additional)
       {
          // Re-use as much as possible, just resetting the body to the trace
          $message['body'] = $additional->getTraceAsString();
          $message['level'] = $this->_log_levels[Log_Writer::$strace_level];
    
          $string .= PHP_EOL.strtr($format, $message);
       }
    
       return $string;
    }
    

    PS: I think you guys should move this ticketing system to github :)

  • This is happening to me too. I'm on nginx/php-fpm 5.4.12

  • I'm also experiencing this on 5.4.12. Good catch

  • Does this happen when you simply call Kohana::$log->add()?

  • Hmm, no, the exception doesn't happen, however, nothing is written in the log file either, just tried on 2 projects. logs/2013/03/04.php is created, with that defined(syspath) or die first line but the actual log message is not written. I used Kohana::$log->add(Kohana_Log::DEBUG, 'asdasd'); (tested with another log level too)

  • Yeah I see, I think the exception is never shown because we write logs in a shutdown handler… if you set Log::$write_on_add to TRUE, you will see the error… so would the solution be to loop through $message and remove anything that isn't a string or integer?

  • Yeah, I would say so...either some array_filter() or transforming everything to string before strtr()

  • Alright, I should be able to fix this over the weekend.

  • Zee,

    I was bugged by this today; so I'm fixing it and adding a pull request, as well as updating ticket #4712.

  • Would this do the trick?

    public function format_message(array $message, $format = "time --- level: body in file:line")
        {
            $message['time'] = Date::formatted_time('@'.$message['time'], Log_Writer::$timestamp, Log_Writer::$timezone, TRUE);
            $message['level'] = $this->_log_levels[$message['level']];
            unset($message['trace']);
            if (isset($message['additional']['exception'])) {
                $exception = $message['additional']['exception'];
                unset($message['additional']);
            }
            $string = strtr($format, $message);
            if (isset($exception))
            {
                // Re-use as much as possible, just resetting the body to the trace
                $message['body'] = $exception->getTraceAsString();
                $message['level'] = $this->_log_levels[Log_Writer::$strace_level];
    
                $string .= PHP_EOL.strtr($format, $message);
            }
    
            return $string;
        }
    
  • we've already fixed the issue in the 3.3/develop branch, if you need this before 3.3.1 is released, you can grab the change from there

  • is there any quick solution or hack to avoid upgrading to 3.3.1 ?

  • Take the fix from the 3.3/develop branch and make the same change in your application directory.

  • Don't get me wrong: I very much appreciate everything you devs are doing to make my life(/hobby) easier - but I thought these kinds of little bugs slipping through the cracks warrant a .1 release. I can only presume everyone using 3.3 is caught by this bug...

  • Hi!

    About $message['level']

    echo Debug::vars($message['level']); // 7
    

    Step 1

    echo Debug::vars($message);
    

    In my case it

    array(7) (
        "time" => string(19) "2013-06-08 14:04:51"
        "level" => integer 7
        "body" => string(25) "My message"
        "hostname" => string(9) "127.0.0.1"
        "user_agent" => string(105) "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"
        "url" => string(5) "another/path"
        "referer" => string(29) "http://site.com/some/path"
    )
    

    Step 2

    echo Debug::Vars($this->_log_levels);
    

    In my case it

    array(8) (
        0 => string(9) "EMERGENCY"
        1 => string(5) "ALERT"
        2 => string(8) "CRITICAL"
        3 => string(5) "ERROR"
        4 => string(7) "WARNING"
        5 => string(6) "NOTICE"
        6 => string(4) "INFO"
        7 => string(5) "DEBUG"
    )
    

    If I knowingly do a mistake, I see a white screen with single string:

    ErrorException [ 8 ]: Undefined offset: 8 ~ MODPATH/myapp/path/to/log/writer.php [ 104 ]
    

    Line 104 is it

    $message['level'] = $this->_log_levels[$message['level']];
    

    If I use the following code $message['level'] = $this->_log_levels[7]; everything is fine. What's the problem?

    May be should be $message['level'] = Arr::get($this->_log_levels, $message['level']); ?

    About $message['level']

    May be should be

    Date::formatted_time('@'.$message['time'], Log_Writer::$timestamp, Log_Writer::$timezone);
    

    instead

    Date::formatted_time('@'.$message['time'], Log_Writer::$timestamp, Log_Writer::$timezone, TRUE);
    

    ?

    Method Date::formatted_time should take 3 arguments, not 4:

    public static function formatted_time($datetime_str = 'now', $timestamp_format = NULL, $timezone = NULL)
    

    Thanks

  • yeah I got tripped up with this on a php 5.4.16 deploy too... will get the fix from the 3.3 dev trunk prior to an interim release.

Howdy, Stranger!

It looks like you're new here. If you want to get involved, click one of these buttons!

In this Discussion