Imbalanced AphrontWriteGuard: more beginUnguardedWrites() calls than endUnguardedWrites() calls
Open, HighPublic
Actions

Assigned To

None

Authored By

	Sten
	Tue, Apr 30, 10:18

Description

Started to get the following Exception following the server's Centos RPMs being updated:

PHP message: [2024-04-30 09:23:46] EXCEPTION: (Exception) Imbalanced AphrontWriteGuard: more beginUnguardedWrites() calls than endUnguardedWrites() calls. at [<phorge>/src/aphront/writeguard/AphrontWriteGuard.php:99]
PHP message: arcanist(head=master, ref.master=ba42b63704b2, custom=4), phorge(head=master, ref.master=318d7a61feab)
PHP message:   #0 <#2> AphrontWriteGuard::dispose() called at [<phorge>/src/aphront/configuration/AphrontApplicationConfiguration.php:214]
PHP message:   #1 <#2> AphrontApplicationConfiguration::runHTTPRequest(AphrontPHPHTTPSink) called at [<phorge>/webroot/index.php:35]
PHP message:   #2 phlog(Exception) called at [<phorge>/src/aphront/response/AphrontUnhandledExceptionResponse.php:32]
PHP message:   #3 AphrontUnhandledExceptionResponse::setException(Exception) called at [<phorge>/webroot/index.php:46]

This exception would be triggered by running arc diff or arc branches

The fix is:

--- a/src/applications/conduit/controller/PhabricatorConduitAPIController.php
+++ b/src/applications/conduit/controller/PhabricatorConduitAPIController.php
@@ -76,7 +76,7 @@ final class PhabricatorConduitAPIController

       if ($auth_error === null) {
         if ($allow_unguarded_writes) {
-          $unguarded = AphrontWriteGuard::beginScopedUnguardedWrites();
+          AphrontWriteGuard::beginUnguardedWrites();
         }

         try {
@@ -92,8 +92,9 @@ final class PhabricatorConduitAPIController
             $error_info = $call->getErrorDescription($error_code);
           }
         }
+
         if ($allow_unguarded_writes) {
-          unset($unguarded);
+          AphrontWriteGuard::endUnguardedWrites();
         }
       } else {
         list($error_code, $error_info) = $auth_error;

Event Timeline

Sten created this task.Tue, Apr 30, 10:18

Herald added subscribers: Cigaryno, Matthew, chris, tobiaswiese. · View Herald TranscriptTue, Apr 30, 10:18

Sten updated the task description. (Show Details)Tue, Apr 30, 10:19

Thanks. Premising that I cannot reproduce the issue. I use arc diff and arc branches frequently without issues 🤔 Tested both with and without authentication.

Also it's strange that the stack trace does not mention PhabricatorConduitAPIController

To find it, I needed to put in loads of debugging. It seems to be an issue with PHP deferring the execution of the object destructor until after the Imbalanced AphrontWriteGuard check, even though the object was unset prior to the check.

The issue occurs in Remi PHP 8.1.28, which is currently the latest 8.1 version

Had this issue occur elsewhere, so put a general 'fix' for it:

--- a/src/aphront/writeguard/AphrontWriteGuard.php
+++ b/src/aphront/writeguard/AphrontWriteGuard.php
@@ -96,12 +96,13 @@ final class AphrontWriteGuard extends Phobject {
     }

     if ($this->allowDepth > 0) {
-      throw new Exception(
+      phlog( new Exception(
         pht(
           'Imbalanced %s: more %s calls than %s calls.',
           __CLASS__,
           'beginUnguardedWrites()',
-          'endUnguardedWrites()'));
+          'endUnguardedWrites()'))
+      );
     }

Also starting to see other destructor related issues with Mediawiki, so this is almost certainly caused by PHP. Putting the 'fix' in here for anyone else who sees the error until PHP is updated!

I was not aware that we were executing critical business code inside __destruct() automagic calls. Wow!

https://we.phorge.it/source/phorge/browse/master/src/aphront/writeguard/AphrontScopedUnguardedWriteCapability.php

I agree with you if you think that the above approach is too much esoteric and creative.

So, if you see similar things:

$unguarded = AphrontWriteGuard::beginScopedUnguardedWrites();

// very interesting things

unset(unguarded)

You are very welcome in replacing that with something less esoteric, like:

// Make sure to end.
AphrontWriteGuard::beginUnguardedWrites();

try {

  // very interesting things

} finally {
  AphrontWriteGuard::endUnguardedWrites()
}

Or something similar.

Setting high priority since I'm scared :D Feel free to re-tune

Imbalanced AphrontWriteGuard: more beginUnguardedWrites() calls than endUnguardedWrites() callsOpen, HighPublicActions

Description

Event Timeline

Imbalanced AphrontWriteGuard: more beginUnguardedWrites() calls than endUnguardedWrites() calls
Open, HighPublic
Actions