From 35539a019ce1ceb32574822101e607f7e1eb49e0 Mon Sep 17 00:00:00 2001 From: epriestley Date: Sat, 6 Apr 2019 10:31:58 -0700 Subject: [PATCH] Add an optional protocol log to `git` SSH workflows Summary: Ref T8093. Support dumping the protocol bytes to a side channel logfile, as a precursor to parsing the protocol and rewriting protocol frames to virtualize refs. The protocol itself is mostly ASCII text so the raw protocol bytes are pretty comprehensible. Test Plan: {F6363221} {F6363222} Reviewers: amckinley Reviewed By: amckinley Maniphest Tasks: T8093 Differential Revision: https://secure.phabricator.com/D20380 --- src/__phutil_library_map__.php | 2 + .../DiffusionGitReceivePackSSHWorkflow.php | 13 +- .../diffusion/ssh/DiffusionGitSSHWorkflow.php | 51 +++++ .../ssh/DiffusionGitUploadPackSSHWorkflow.php | 10 + .../log/PhabricatorProtocolLog.php | 193 ++++++++++++++++++ 5 files changed, 268 insertions(+), 1 deletion(-) create mode 100644 src/infrastructure/log/PhabricatorProtocolLog.php diff --git a/src/__phutil_library_map__.php b/src/__phutil_library_map__.php index 1de91d68ba..86c35f105e 100644 --- a/src/__phutil_library_map__.php +++ b/src/__phutil_library_map__.php @@ -4284,6 +4284,7 @@ phutil_register_library_map(array( 'PhabricatorProjectsSearchEngineExtension' => 'applications/project/engineextension/PhabricatorProjectsSearchEngineExtension.php', 'PhabricatorProjectsWatchersSearchEngineAttachment' => 'applications/project/engineextension/PhabricatorProjectsWatchersSearchEngineAttachment.php', 'PhabricatorPronounSetting' => 'applications/settings/setting/PhabricatorPronounSetting.php', + 'PhabricatorProtocolLog' => 'infrastructure/log/PhabricatorProtocolLog.php', 'PhabricatorPygmentSetupCheck' => 'applications/config/check/PhabricatorPygmentSetupCheck.php', 'PhabricatorQuery' => 'infrastructure/query/PhabricatorQuery.php', 'PhabricatorQueryConstraint' => 'infrastructure/query/constraint/PhabricatorQueryConstraint.php', @@ -10491,6 +10492,7 @@ phutil_register_library_map(array( 'PhabricatorProjectsSearchEngineExtension' => 'PhabricatorSearchEngineExtension', 'PhabricatorProjectsWatchersSearchEngineAttachment' => 'PhabricatorSearchEngineAttachment', 'PhabricatorPronounSetting' => 'PhabricatorSelectSetting', + 'PhabricatorProtocolLog' => 'Phobject', 'PhabricatorPygmentSetupCheck' => 'PhabricatorSetupCheck', 'PhabricatorQuery' => 'Phobject', 'PhabricatorQueryConstraint' => 'Phobject', diff --git a/src/applications/diffusion/ssh/DiffusionGitReceivePackSSHWorkflow.php b/src/applications/diffusion/ssh/DiffusionGitReceivePackSSHWorkflow.php index 54220f0776..abf2a4323e 100644 --- a/src/applications/diffusion/ssh/DiffusionGitReceivePackSSHWorkflow.php +++ b/src/applications/diffusion/ssh/DiffusionGitReceivePackSSHWorkflow.php @@ -28,7 +28,8 @@ final class DiffusionGitReceivePackSSHWorkflow extends DiffusionGitSSHWorkflow { ->setRepository($repository) ->setLog($this); - if ($this->shouldProxy()) { + $is_proxy = $this->shouldProxy(); + if ($is_proxy) { $command = $this->getProxyCommand(true); $did_write = false; @@ -51,6 +52,12 @@ final class DiffusionGitReceivePackSSHWorkflow extends DiffusionGitSSHWorkflow { } } + $log = $this->newProtocolLog($is_proxy); + if ($log) { + $this->setProtocolLog($log); + $log->didStartSession($command); + } + $caught = null; try { $err = $this->executeRepositoryCommand($command); @@ -58,6 +65,10 @@ final class DiffusionGitReceivePackSSHWorkflow extends DiffusionGitSSHWorkflow { $caught = $ex; } + if ($log) { + $log->didEndSession(); + } + // We've committed the write (or rejected it), so we can release the lock // without waiting for the client to receive the acknowledgement. if ($did_write) { diff --git a/src/applications/diffusion/ssh/DiffusionGitSSHWorkflow.php b/src/applications/diffusion/ssh/DiffusionGitSSHWorkflow.php index 6bc56d767d..578c6b1e03 100644 --- a/src/applications/diffusion/ssh/DiffusionGitSSHWorkflow.php +++ b/src/applications/diffusion/ssh/DiffusionGitSSHWorkflow.php @@ -5,6 +5,7 @@ abstract class DiffusionGitSSHWorkflow implements DiffusionRepositoryClusterEngineLogInterface { private $engineLogProperties = array(); + private $protocolLog; protected function writeError($message) { // Git assumes we'll add our own newlines. @@ -55,4 +56,54 @@ abstract class DiffusionGitSSHWorkflow $repository->getVersionControlSystem())); } + protected function newPassthruCommand() { + return parent::newPassthruCommand() + ->setWillWriteCallback(array($this, 'willWriteMessageCallback')) + ->setWillReadCallback(array($this, 'willReadMessageCallback')); + } + + protected function newProtocolLog($is_proxy) { + if ($is_proxy) { + return null; + } + + // While developing, do this to write a full protocol log to disk: + // + // return new PhabricatorProtocolLog('/tmp/git-protocol.log'); + + return null; + } + + protected function getProtocolLog() { + return $this->protocolLog; + } + + protected function setProtocolLog(PhabricatorProtocolLog $log) { + $this->protocolLog = $log; + } + + public function willWriteMessageCallback( + PhabricatorSSHPassthruCommand $command, + $message) { + + $log = $this->getProtocolLog(); + if ($log) { + $log->didWriteBytes($message); + } + + return $message; + } + + public function willReadMessageCallback( + PhabricatorSSHPassthruCommand $command, + $message) { + + $log = $this->getProtocolLog(); + if ($log) { + $log->didReadBytes($message); + } + + return $message; + } + } diff --git a/src/applications/diffusion/ssh/DiffusionGitUploadPackSSHWorkflow.php b/src/applications/diffusion/ssh/DiffusionGitUploadPackSSHWorkflow.php index e96030f577..c8c779feb3 100644 --- a/src/applications/diffusion/ssh/DiffusionGitUploadPackSSHWorkflow.php +++ b/src/applications/diffusion/ssh/DiffusionGitUploadPackSSHWorkflow.php @@ -54,11 +54,21 @@ final class DiffusionGitUploadPackSSHWorkflow extends DiffusionGitSSHWorkflow { $future = id(new ExecFuture('%C', $command)) ->setEnv($this->getEnvironment()); + $log = $this->newProtocolLog($is_proxy); + if ($log) { + $this->setProtocolLog($log); + $log->didStartSession($command); + } + $err = $this->newPassthruCommand() ->setIOChannel($this->getIOChannel()) ->setCommandChannelFromExecFuture($future) ->execute(); + if ($log) { + $log->didEndSession(); + } + if ($err) { $pull_event ->setResultType(PhabricatorRepositoryPullEvent::RESULT_ERROR) diff --git a/src/infrastructure/log/PhabricatorProtocolLog.php b/src/infrastructure/log/PhabricatorProtocolLog.php new file mode 100644 index 0000000000..d2775b27de --- /dev/null +++ b/src/infrastructure/log/PhabricatorProtocolLog.php @@ -0,0 +1,193 @@ +logfile = $logfile; + } + + public function didStartSession($session_name) { + $this->setMode('!'); + $this->buffer[] = $session_name; + $this->flush(); + } + + public function didEndSession() { + $this->setMode('_'); + $this->buffer[] = pht(''); + $this->flush(); + } + + public function didWriteBytes($bytes) { + if (!strlen($bytes)) { + return; + } + + $this->setMode('>'); + $this->buffer[] = $bytes; + } + + public function didReadBytes($bytes) { + if (!strlen($bytes)) { + return; + } + + $this->setMode('<'); + $this->buffer[] = $bytes; + } + + private function setMode($mode) { + if ($this->mode === $mode) { + return $this; + } + + if ($this->mode !== null) { + $this->flush(); + } + + $this->mode = $mode; + + return $this; + } + + private function flush() { + $mode = $this->mode; + $bytes = $this->buffer; + + $this->mode = null; + $this->buffer = array(); + + $bytes = implode('', $bytes); + + if (strlen($bytes)) { + $this->writeBytes($mode, $bytes); + } + } + + private function writeBytes($mode, $bytes) { + $header = $mode; + $len = strlen($bytes); + + $out = array(); + switch ($mode) { + case '<': + $out[] = pht('%s Write [%s bytes]', $header, new PhutilNumber($len)); + break; + case '>': + $out[] = pht('%s Read [%s bytes]', $header, new PhutilNumber($len)); + break; + default: + $out[] = pht( + '%s %s', + $header, + $this->escapeBytes($bytes)); + break; + } + + switch ($mode) { + case '<': + case '>': + $out[] = $this->renderBytes($header, $bytes); + break; + } + + $out = implode("\n", $out)."\n\n"; + + $this->writeMessage($out); + } + + private function renderBytes($header, $bytes) { + $bytes_per_line = 48; + $bytes_per_chunk = 4; + + // Compute the width of the "bytes" display section, which looks like + // this: + // + // > 00112233 44556677 abcdefgh + // ^^^^^^^^^^^^^^^^^ + // + // We need to figure this out so we can align the plain text in the far + // right column appropriately. + + // The character width of the "bytes" part of a full display line. If + // we're rendering 48 bytes per line, we'll need 96 characters, since + // each byte is printed as a 2-character hexadecimal code. + $display_bytes = ($bytes_per_line * 2); + + // The character width of the number of spaces in between the "bytes" + // chunks. If we're rendering 12 chunks per line, we'll put 11 spaces + // in between them to separate them. + $display_spaces = (($bytes_per_line / $bytes_per_chunk) - 1); + + $pad_bytes = $display_bytes + $display_spaces; + + // When the protocol is plaintext, try to break it on newlines so it's + // easier to read. + $pos = 0; + $lines = array(); + while (true) { + $next_break = strpos($bytes, "\n", $pos); + if ($next_break === false) { + $len = strlen($bytes) - $pos; + } else { + $len = ($next_break - $pos) + 1; + } + $len = min($bytes_per_line, $len); + + $next_bytes = substr($bytes, $pos, $len); + + $chunk_parts = array(); + foreach (str_split($next_bytes, $bytes_per_chunk) as $chunk) { + $chunk_display = ''; + for ($ii = 0; $ii < strlen($chunk); $ii++) { + $chunk_display .= sprintf('%02x', ord($chunk[$ii])); + } + $chunk_parts[] = $chunk_display; + } + $chunk_parts = implode(' ', $chunk_parts); + + $chunk_parts = str_pad($chunk_parts, $pad_bytes, ' '); + + + $lines[] = $header.' '.$chunk_parts.' '.$this->escapeBytes($next_bytes); + + $pos += $len; + + if ($pos >= strlen($bytes)) { + break; + } + } + + $lines = implode("\n", $lines); + + return $lines; + } + + private function escapeBytes($bytes) { + $result = ''; + for ($ii = 0; $ii < strlen($bytes); $ii++) { + $c = $bytes[$ii]; + $o = ord($c); + + if ($o >= 0x20 && $o <= 0x7F) { + $result .= $c; + } else { + $result .= '.'; + } + } + return $result; + } + + private function writeMessage($message) { + $f = fopen($this->logfile, 'a'); + fwrite($f, $message); + fflush($f); + fclose($f); + } + +}