Skip to content

PHPLIB-1177: SDAM logger example #1142

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Aug 18, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
145 changes: 145 additions & 0 deletions examples/sdam_logger.php
Original file line number Diff line number Diff line change
@@ -0,0 +1,145 @@
<?php
declare(strict_types=1);

namespace MongoDB\Examples;

use MongoDB\Client;
use MongoDB\Driver\Monitoring\SDAMSubscriber;
use MongoDB\Driver\Monitoring\ServerChangedEvent;
use MongoDB\Driver\Monitoring\ServerClosedEvent;
use MongoDB\Driver\Monitoring\ServerHeartbeatFailedEvent;
use MongoDB\Driver\Monitoring\ServerHeartbeatStartedEvent;
use MongoDB\Driver\Monitoring\ServerHeartbeatSucceededEvent;
use MongoDB\Driver\Monitoring\ServerOpeningEvent;
use MongoDB\Driver\Monitoring\TopologyChangedEvent;
use MongoDB\Driver\Monitoring\TopologyClosedEvent;
use MongoDB\Driver\Monitoring\TopologyOpeningEvent;

use function get_class;
use function getenv;
use function MongoDB\BSON\fromPHP;
use function MongoDB\BSON\toRelaxedExtendedJSON;
use function printf;

require __DIR__ . '/../vendor/autoload.php';

/** @param array|object $document */
function toJSON($document): string
{
return toRelaxedExtendedJSON(fromPHP($document));
}

class SDAMLogger implements SDAMSubscriber
{
public function serverChanged(ServerChangedEvent $event): void
{
printf(
"serverChanged: %s:%d changed from %s to %s\n",
$event->getHost(),
$event->getPort(),
$event->getPreviousDescription()->getType(),
$event->getNewDescription()->getType(),
);

printf("previous hello response: %s\n", toJson($event->getPreviousDescription()->getHelloResponse()));
printf("new hello response: %s\n", toJson($event->getNewDescription()->getHelloResponse()));
echo "\n";
}

public function serverClosed(ServerClosedEvent $event): void
{
printf(
"serverClosed: %s:%d was removed from topology %s\n",
$event->getHost(),
$event->getPort(),
(string) $event->getTopologyId(),
);
echo "\n";
}

public function serverHeartbeatFailed(ServerHeartbeatFailedEvent $event): void
{
printf(
"serverHeartbeatFailed: %s:%d heartbeat failed after %dµs\n",
$event->getHost(),
$event->getPort(),
$event->getDurationMicros(),
);

$error = $event->getError();

printf("error: %s(%d): %s\n", get_class($error), $error->getCode(), $error->getMessage());
echo "\n";
}

public function serverHeartbeatStarted(ServerHeartbeatStartedEvent $event): void
{
printf(
"serverHeartbeatStarted: %s:%d heartbeat started\n",
$event->getHost(),
$event->getPort(),
);
echo "\n";
}

public function serverHeartbeatSucceeded(ServerHeartbeatSucceededEvent $event): void
{
printf(
"serverHeartbeatSucceeded: %s:%d heartbeat succeeded after %dµs\n",
$event->getHost(),
$event->getPort(),
$event->getDurationMicros(),
);

printf("reply: %s\n", toJson($event->getReply()));
echo "\n";
}

public function serverOpening(ServerOpeningEvent $event): void
{
printf(
"serverOpening: %s:%d was added to topology %s\n",
$event->getHost(),
$event->getPort(),
(string) $event->getTopologyId(),
);
echo "\n";
}

public function topologyChanged(TopologyChangedEvent $event): void
{
printf(
"topologyChanged: %s changed from %s to %s\n",
(string) $event->getTopologyId(),
$event->getPreviousDescription()->getType(),
$event->getNewDescription()->getType(),
);
echo "\n";
}

public function topologyClosed(TopologyClosedEvent $event): void
{
printf("topologyClosed: %s was closed\n", (string) $event->getTopologyId());
echo "\n";
}

public function topologyOpening(TopologyOpeningEvent $event): void
{
printf("topologyOpening: %s was opened\n", (string) $event->getTopologyId());
echo "\n";
}
}

/* Note: TopologyClosedEvent can only be observed for non-persistent clients.
* Persistent clients are destroyed in GSHUTDOWN, long after any PHP objects
* (including subscribers) are freed. */
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Comment lifted from topologyClosedEvent-001.phpt in PHPC, which also had a typo I fixed in mongodb/mongo-php-driver#1456.

$client = new Client(getenv('MONGODB_URI') ?: 'mongodb://127.0.0.1/', [], ['disableClientPersistence' => true]);

$client->getManager()->addSubscriber(new SDAMLogger());

$client->test->command(['ping' => 1]);

/* Events dispatched during mongoc_client_destroy can only be observed before
* RSHUTDOWN. Observing TopologyClosedEvent requires using a non-persistent
* client and freeing it before the script ends. */
unset($client);
17 changes: 17 additions & 0 deletions tests/ExamplesTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -128,6 +128,23 @@ public static function provideExamples(): Generator
'expectedOutput' => $expectedOutput,
];

/* Note: Do not assert output beyond the initial topology events, as it
* may vary based on the test environment. PHPUnit's matching behavior
* for "%A" also seems to differ slightly from run-tests.php, otherwise
* we could assert the final topologyClosed event. */
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I looked through StringMatchesFormatDescription but couldn't figure out exactly why it differs from run-tests.php. In my local testing, PHPUnit had trouble matching expected output after %A, in contrast to the attached sdam_logger.phpt file (ignore the txt extension, which was needed to appease GitHub's validation).

Relevant format in the phpt test is:

--EXPECTF--
topologyOpening: %x was opened

topologyChanged: %x changed from Unknown to %s

%A

topologyChanged: %x changed from %s to %s

topologyClosed: %x was closed

===DONE===

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The PHPUnit StringMatchesFormatDescription splits line-by-line. So you cannot match several lines with a single %A. This works on my machine:

        $expectedOutput = <<<'OUTPUT'
topologyOpening: %x was opened

topologyChanged: %x changed from Unknown to %s

%A
%A
%A
%A
%A
%A
%A
%A
%A
%A

topologyChanged: %x changed from %s to %s

topologyClosed: %x was closed


OUTPUT;

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The PHPUnit StringMatchesFormatDescription splits line-by-line

Can you point me to where that happens? I know that StringMatchesFormatDescription has some logic to convert \r\n (e.g. sebastianbergmann/phpunit@05db035), but it looks like it defers to preg_match to handle multi-line strings.

A series of %A patterns on their own line should be redundant, as that could otherwise be written with %S (see: EXPECTF. And the regex conversion seemingly does attempt to handle newlines for %a and %A based on the conversion logic in regularExpressionForFormatDescription():

'%s' => '[^\r\n]+',
'%S' => '[^\r\n]*',
'%a' => '.+',
'%A' => '.*',

Asserting the number of newlines in the output is not portable, as that will vary based on the topology used to run the test. A 3-member replica set is going to log more lines than a 2-mongos sharded cluster or standalone server.

Copy link
Member

@GromNaN GromNaN Aug 14, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've been confused by the additionalFailureDescription that does split lines.

$expectedOutput = <<<'OUTPUT'
topologyOpening: %x was opened

topologyChanged: %x changed from Unknown to %s

%A
OUTPUT;

yield 'sdam_logger' => [
'file' => __DIR__ . '/../examples/sdam_logger.php',
'expectedOutput' => $expectedOutput,
];

$expectedOutput = <<<'OUTPUT'
MongoDB\Examples\TypeMapEntry Object
(
Expand Down