Page MenuHomePhabricator

Broken Log Formatting for Page Moves
Closed, ResolvedPublic

Description

Author: dasch

Description:
When accessing Special:Recent_Changes I get this error. Other pages work normal and logging is disabled in my configuration.

Warning: Invalid argument supplied for foreach() in /.../httpdocs/includes/logging/LogFormatter.php on line 179

Catchable fatal error: Argument 1 passed to LogFormatter::makePageLink() must be an instance of Title, null given, called in /.../httpdocs/includes/logging/LogFormatter.php on line 337 and defined in /var/www/vhosts/wecowi.de/httpdocs/includes/logging/LogFormatter.php on line 206


Version: 1.20.x
Severity: major

Details

Reference
bz30854
TitleReferenceAuthorSource BranchDest Branch
fix mypy warningsrepos/data-engineering/eventutilities-python!26gmodenaT328547-fix-mypy-warningsmain
Address linter error and warningsrepos/data-engineering/eventutilities-python!24gmodenaT328547-mypy-linter-checksmain
Customize query in GitLab

Event Timeline

bzimport raised the priority of this task from to High.Nov 21 2014, 11:53 PM
bzimport set Reference to bz30854.

Can you add this code to LogFormatter before line 179 and post the results

		if ( !is_array( $entry->getParameters() ) ) {
			var_dump( $entry ); die();
		}

Or can you provide the results of this mysql command:
select rc_log_type, rc_log_action, rc_params from recentchanges where rc_type = 3 order by rc_id desc limit 50;

dasch wrote:

That's the result

object(RCDatabaseLogEntry)#502 (3) { ["row:protected"]=> object(stdClass)#498 (30) { ["rc_id"]=> string(5) "92568" ["rc_timestamp"]=> string(14) "20110906212954" ["rc_cur_time"]=> string(14) "20110906212954" ["rc_user"]=> string(1) "1" ["rc_user_text"]=> string(5) "DaSch" ["rc_namespace"]=> string(1) "0" ["rc_title"]=> string(38) "Sympathy_for_the_Devil_(One_Tree_Hill)" ["rc_comment"]=> string(0) "" ["rc_minor"]=> string(1) "0" ["rc_bot"]=> string(1) "0" ["rc_new"]=> string(1) "0" ["rc_cur_id"]=> string(5) "15933" ["rc_this_oldid"]=> string(1) "0" ["rc_last_oldid"]=> string(1) "0" ["rc_type"]=> string(1) "3" ["rc_moved_to_ns"]=> string(1) "0" ["rc_moved_to_title"]=> string(0) "" ["rc_patrolled"]=> string(1) "1" ["rc_ip"]=> string(13) "92.224.225.44" ["rc_old_len"]=> NULL ["rc_new_len"]=> NULL ["rc_deleted"]=> string(1) "0" ["rc_logid"]=> string(5) "41633" ["rc_log_type"]=> string(4) "move" ["rc_log_action"]=> string(4) "move" ["rc_params"]=> string(36) "Stunde der Wahrheit (One Tree Hill) " ["wl_user"]=> string(1) "1" ["wl_notificationtimestamp"]=> NULL ["page_latest"]=> string(6) "110655" ["ts_tags"]=> NULL } ["params"]=> string(36) "Stunde der Wahrheit (One Tree Hill) " ["legacy"]=> bool(false) }

dasch wrote:

And that is the result of the SQL command

rc_log_type rc_log_action rc_params
upload upload [BLOB - 0Bytes]
move move [BLOB - 36Bytes]
move move [BLOB - 35Bytes]
move move [BLOB - 38Bytes]
move move [BLOB - 41Bytes]
move move [BLOB - 36Bytes]
move move [BLOB - 35Bytes]
move move [BLOB - 41Bytes]
move move [BLOB - 32Bytes]
move move [BLOB - 27Bytes]
move move [BLOB - 36Bytes]
move move [BLOB - 42Bytes]
move move [BLOB - 52Bytes]
delete delete [BLOB - 0Bytes]
move move [BLOB - 60Bytes]
delete delete [BLOB - 0Bytes]
move move [BLOB - 32Bytes]
move move [BLOB - 31Bytes]
move move [BLOB - 37Bytes]
move move [BLOB - 40Bytes]
import interwiki [BLOB - 0Bytes]
move move [BLOB - 15Bytes]
move move [BLOB - 19Bytes]
upload upload [BLOB - 0Bytes]
move move [BLOB - 24Bytes]
import interwiki [BLOB - 0Bytes]
move move [BLOB - 26Bytes]
move move [BLOB - 29Bytes]
move move [BLOB - 19Bytes]
move move [BLOB - 25Bytes]
move move [BLOB - 34Bytes]
move move [BLOB - 27Bytes]
move move [BLOB - 31Bytes]
move move [BLOB - 30Bytes]
move move [BLOB - 28Bytes]
move move [BLOB - 23Bytes]
move move [BLOB - 24Bytes]
move move [BLOB - 26Bytes]
move move [BLOB - 22Bytes]
move move [BLOB - 22Bytes]
move move [BLOB - 21Bytes]
move move [BLOB - 20Bytes]
move move [BLOB - 25Bytes]
move move [BLOB - 28Bytes]
move move [BLOB - 26Bytes]
move move [BLOB - 23Bytes]
move move [BLOB - 22Bytes]
import interwiki [BLOB - 0Bytes]
import interwiki [BLOB - 0Bytes]
import interwiki [BLOB - 0Bytes]

Which revision is this? I don't understand how the current code would return non-array:

["params"]=> string(36) "Stunde der Wahrheit (One Tree Hill) " ["legacy"]=> bool(false)

The relevant code is here:

public function getParameters() {
if ( !isset( $this->params ) ) {

		$blob = $this->getRawParameters();
		wfSuppressWarnings();
		$params = unserialize( $blob );
		wfRestoreWarnings();
		if ( $params !== false ) {
			$this->params = $params;
			$this->legacy = false;
		} else {
			$params = FormatJson::decode( $blob, true /* array */ );
			if ( $params !== null ) {
				$this->params = $params;
				$this->legacy = false;
			} else {
				$this->params = $blob === '' ? array() : explode( "\n", $blob );
				$this->legacy = true;
			}
		}

}
return $this->params;
}

dasch wrote:

I have r96776 and have no idea about this :(
Maybe this error is caused by the changes from r96585

I can't think of anything else, but that either unserialize() doesn't return false, or FormatJson::decode doesn't return null. Can you play around with the code and check if that is the case?

dasch wrote:

it seams that $this->params is already set when entering the function getParameters
I added this before the return
else { echo "already set to: "; var_dump($this->params); }
and got this result:
already set to: string(36) "Stunde der Wahrheit (One Tree Hill) "

You probably see that because that function is called twice, first through isLegacy() and then getParameters() directly. Otherwise $this->legacy would have been unset.

dasch wrote:

I have the impression that the numbering of the params is not correct

I added this
if ( !isset($params[3]) ) {$params[3]="WARNING: Missing!";}
in getMessageParameters before return

the result you can see here

http://www.wecowi.de/wiki/Spezial:Logbuch/move

The targetPage is missing

Of course it is missing, that's why the PHP complains.

You should be investigating what happens inside DatabaseLogEntry::getParameters() method.

dasch wrote:

The strange thing is, that the missing string is what is given through $entry->getParameters()
it is a string like I added through the if. But when using
$params[3] = $entry->getParameters();
it does not work
altough printing $params[3] after setting it gives the correct page name
but somehow it disappears short after

dasch wrote:

To avoid that DatabaseLogEntry::getParameters() return a string instead of an array I added this before the return

		if ( is_string($this->params) ) {
			$paramString = $this->params;
			$this->params = array();
			$this->params[0] = $paramString;
		}

The warning disappears but the error remains
so somehow even if the array exists how it should the target page still is not added correctly

dasch wrote:

I added
$this->legacy = true;
to the if give above
Know in LogFormatter::getMessageParameters() in the if that checks for legacy the param is added correctly to position 3. And the params array is returned correctly with entrys 0-3 but in MoveLogFormatter::getMessageParameters it is still missing

dasch wrote:

I think the problem is, that
Title::newFromText( $params[3] )
returns NULL

dasch wrote:

I think the return value of Title::newFromText is not correct or not handled correctly

dasch wrote:

Can anybody check this for a clean install?
Will this be a migration issue or does the move-log not work at any enviorment?

Can you check the return values of unserialize( $blob ) and FormatJson::decode( $blob, true /* array */ ) in DatabaseLogEntry getParameters()?

dasch wrote:

In the database the value of rc_params is a string for move entries. So everything is correct. The string is correctly passed through DatabaseLogEntry when conversion from the string to an array like described above to $params[3]. But then when Title::newFromText( $params[3] ) is executed it returns NULL when the page exists and then the value is lost and then the creation of the pagelink fails.

This warning clearly says that it is *not* an array that is returned:
Warning: Invalid argument supplied for foreach() in
/.../httpdocs/includes/logging/LogFormatter.php on line 179

dasch wrote:

Therfore I added this
(In reply to comment #12)

To avoid that DatabaseLogEntry::getParameters() return a string instead of an
array I added this before the return

if ( is_string($this->params) ) {
    $paramString = $this->params;
    $this->params = array();
    $this->params[0] = $paramString;
}

The warning disappears but the error remains
so somehow even if the array exists how it should the target page still is not
added correctly

There can not be an array returend because the blob in the database is only a string

That function must always return an array. It should go through the legacy = true path, which uses explode( '\n' ) to make an array of the string. However, in this case it is taking one of the two other parts - why - that doesn't make any sense to me. That's why I'd like to know a) which path it is b) what is the value of $params when that path is taken.

dasch wrote:

But when there ist no \n in the string it can not create an array because there is nothing to explode

The point is that the real problem occures at the end. When Title::newFromText is applyed witch does not return an instance of Title, but null and forces makePagelink to fail!

But it doesn't even try to explode, I can see that from legacy=false.
If it would, it would return an array:

var_dump( explode( "\n", "cat" ) );

array(1) {

[0]=>
string(3) "cat"

}

dasch wrote:

I have the impression that we totally talk past each other and have no idea what to test, to try or whatever

dasch wrote:

Okay... well
DatabaseLogEntry::getParameters()
returns the following

$params = unserialize( $blob );
var_dump($params);
is false

$params = FormatJson::decode( $blob, true /* array */ );
var_dump($params);
is string

dasch wrote:

BTW: when passing a string to json_decode it always return the same. Check
echo json_decode( "cat", false );
echo json_decode( "cat", true );

var_dump( json_decode( 'cat', false ) );
NULL

From PHP manual http://fi.php.net/json_decode:
NULL is returned if the json cannot be decoded or if the encoded data is deeper than the recursion limit.

What version of PHP?

Ah this is the bug: https://bugs.php.net/bug.php?id=45989

I will remove the JSON check, since it isn't even needed. That should fix this bug.

dasch wrote:

My PHP Version is 5.2.4

dasch wrote:

You could also change
if ( $params !== null )
to
if ( $params !== null and is_array($params) )

dasch wrote:

Suggested patch

Attached:

r97039 should fix this. Please test.

stefan.kaifer wrote:

Hi

i've the same problem with 1.20.0.

Page moving not works:

<b>Warning</b>
: call_user_func_array() expects parameter 1 to be a valid callback, function 'MoveLogFormatter' not found or invalid function name in
<b>.../includes/logging/LogPage.php</b>
on line
<b>319</b>

Datenbankfehler
Wechseln zu: Navigation, Suche
Es ist ein Datenbankfehler aufgetreten. Der Grund kann ein Programmierfehler sein. Die letzte Datenbankabfrage lautete:

(Die SQL-Datenbankabfrage ist verborgen.)

aus der Funktion «efUpdateCheckUserData». Die Datenbank meldete den Fehler «1048: Column 'cuc_actiontext' cannot be null (localhost)».

How can i fix this?

Best regards

Stefan

Stefan, you should check the documentation on how to upgrade your MediaWiki and then file a new bug for your issue.