Page MenuHomePhabricator

Clean up some log spam caused by races in VersionedDraft
ClosedPublic

Authored by epriestley on Sep 5 2016, 7:30 PM.
Tags
None
Referenced Files
Unknown Object (File)
Tue, Mar 19, 9:18 PM
Unknown Object (File)
Sat, Mar 16, 12:54 AM
Unknown Object (File)
Sat, Mar 9, 11:07 PM
Unknown Object (File)
Sat, Mar 2, 4:00 PM
Unknown Object (File)
Feb 19 2024, 1:22 PM
Unknown Object (File)
Feb 19 2024, 12:39 PM
Unknown Object (File)
Feb 16 2024, 4:46 PM
Unknown Object (File)
Feb 15 2024, 11:46 AM
Subscribers
None

Details

Summary

Two minor issues that I caught in the log while fixing Phame permissions:

  • We had a JS bug which would cause us to immediately generate two comment previews at the exact same time -- one for loading the page, and one for "switching to desktop". Instead, only generate the "switch to desktop" preview if we really switched to desktop from a different device layout.
  • These two requests could end up reading/writing the VersionedDraft table at exactly the same time fairly often (e.g., after a comment submission, the page would load, send two preview requests at exactly the same time, and they'd race fairly reliably for me locally). If we do race, recover from the race.
Test Plan

Submitted some Phame comments.

  • No more error log errors about VersionedDraft keys.
  • Saw only one preview request when loading the page instead of two.

Here's the specific stack trace I caught:

[Mon Sep 05 12:15:33.639930 2016] [:error] [pid 50608] [client 127.0.0.1:55278] [2016-09-05 14:15:33] EXCEPTION: (AphrontDuplicateKeyQueryException) #1062: Duplicate entry 'PHID-POST-fknnpzjnsdgc3rqobhst-PHID-USER-pr5rjpuilpfserepsd2k-13' for key 'key_object' at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:314]
[Mon Sep 05 12:15:33.640801 2016] [:error] [pid 50608] [client 127.0.0.1:55278] arcanist(head=master, ref.master=9e82ef979e81), corgi(head=master, ref.master=5b9171222bc9), instances(head=stable, ref.master=485bc8128198, ref.stable=2983bc917601), ledger(head=master, ref.master=4da4a24b8779), libcore(), phabricator(head=phame2, ref.master=4b6da9735ba7, ref.phame2=4b6da9735ba7), phutil(head=stable, ref.master=97f05269fdb1, ref.stable=c14343ee620e), services(head=stable, ref.master=1fcb5cdb7582, ref.stable=2d8088a5b4b3)
[Mon Sep 05 12:15:33.640815 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #0 <#2> AphrontBaseMySQLDatabaseConnection::throwCommonException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:348]
[Mon Sep 05 12:15:33.640830 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #1 <#2> AphrontBaseMySQLDatabaseConnection::throwQueryCodeException(integer, string) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:289]
[Mon Sep 05 12:15:33.640833 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #2 <#2> AphrontBaseMySQLDatabaseConnection::throwQueryException(mysqli) called at [<phutil>/src/aphront/storage/connection/mysql/AphrontBaseMySQLDatabaseConnection.php:185]
[Mon Sep 05 12:15:33.640836 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #3 <#2> AphrontBaseMySQLDatabaseConnection::executeRawQuery(string) called at [<phutil>/src/xsprintf/queryfx.php:8]
[Mon Sep 05 12:15:33.640839 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #4 <#2> queryfx(AphrontMySQLiDatabaseConnection, string, string, string, array, string)
[Mon Sep 05 12:15:33.640841 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #5 <#2> call_user_func_array(string, array) called at [<phutil>/src/aphront/storage/connection/AphrontDatabaseConnection.php:42]
[Mon Sep 05 12:15:33.640844 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #6 <#2> AphrontDatabaseConnection::query(string, string, string, array, string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1261]
[Mon Sep 05 12:15:33.640846 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #7 <#2> LiskDAO::insertRecordIntoDatabase(string) called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1106]
[Mon Sep 05 12:15:33.640849 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #8 <#2> LiskDAO::insert() called at [<phabricator>/src/infrastructure/storage/lisk/LiskDAO.php:1075]
[Mon Sep 05 12:15:33.640851 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #9 <#2> LiskDAO::save() called at [<phabricator>/src/applications/draft/storage/PhabricatorVersionedDraft.php:65]
[Mon Sep 05 12:15:33.640854 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #10 <#2> PhabricatorVersionedDraft::loadOrCreateDraft(string, string, integer) called at [<phabricator>/src/applications/transactions/editengine/PhabricatorEditEngine.php:1669]
[Mon Sep 05 12:15:33.640857 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #11 <#2> PhabricatorEditEngine::buildCommentResponse(PhamePost) called at [<phabricator>/src/applications/transactions/editengine/PhabricatorEditEngine.php:894]
[Mon Sep 05 12:15:33.640859 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #12 <#2> PhabricatorEditEngine::buildResponse() called at [<phabricator>/src/applications/phame/controller/post/PhamePostEditController.php:60]
[Mon Sep 05 12:15:33.640862 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #13 <#2> PhamePostEditController::handleRequest(AphrontRequest) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:237]
[Mon Sep 05 12:15:33.640865 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #14 phlog(AphrontDuplicateKeyQueryException) called at [<phabricator>/src/aphront/handler/PhabricatorAjaxRequestExceptionHandler.php:27]
[Mon Sep 05 12:15:33.640868 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #15 PhabricatorAjaxRequestExceptionHandler::handleRequestException(AphrontRequest, AphrontDuplicateKeyQueryException) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:644]
[Mon Sep 05 12:15:33.640870 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #16 AphrontApplicationConfiguration::handleException(AphrontDuplicateKeyQueryException) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:242]
[Mon Sep 05 12:15:33.640873 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #17 AphrontApplicationConfiguration::processRequest(AphrontRequest, PhutilDeferredLog, AphrontPHPHTTPSink, MultimeterControl) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:149]
[Mon Sep 05 12:15:33.640879 2016] [:error] [pid 50608] [client 127.0.0.1:55278]   #18 AphrontApplicationConfiguration::runHTTPRequest(AphrontPHPHTTPSink) called at [<phabricator>/webroot/index.php:17]

Diff Detail

Repository
rP Phabricator
Lint
Lint Not Applicable
Unit
Tests Not Applicable

Event Timeline

epriestley retitled this revision from to Clean up some log spam caused by races in VersionedDraft.
epriestley updated this object.
epriestley edited the test plan for this revision. (Show Details)
epriestley added a reviewer: chad.
chad edited edge metadata.
This revision is now accepted and ready to land.Sep 5 2016, 7:40 PM
This revision was automatically updated to reflect the committed changes.