From 1384dabea99df2d7bab45235736fe0ba515798f5 Mon Sep 17 00:00:00 2001 From: Joas Schilling Date: Tue, 29 Sep 2020 17:14:01 +0200 Subject: Also check responses of 400 errors and so delete unknown devices So before this PR, we tried to act on 400 errors already, but I didn't know that they throw an exception on the `post()`, so instead of performing on the response body, we `continue;` after we logged an info :hushed: This is of course not what was intended. Further more, since the notifications are grouped and the proxy had an error which would immediately bail out with a 400 when there was 1 broken notification, instead of sending the rest, 1 broken notification was enough to not send any notification anymore. And since we never deleted the broken device the instance didn't "heal" itself, but always broke like this. Signed-off-by: Joas Schilling --- lib/Push.php | 63 ++++++++++++++++++++++++++++++++++++++++-------------------- 1 file changed, 42 insertions(+), 21 deletions(-) diff --git a/lib/Push.php b/lib/Push.php index d377df8..ce86c06 100644 --- a/lib/Push.php +++ b/lib/Push.php @@ -263,44 +263,65 @@ class Push { 'notifications' => $notifications, ], ]); - } catch (\Exception $e) { - $this->log->logException($e, [ - 'app' => 'notifications', - 'level' => $e->getCode() === Http::STATUS_BAD_REQUEST ? ILogger::INFO : ILogger::WARN, - ]); - continue; - } - - $status = $response->getStatusCode(); - if ($status === Http::STATUS_SERVICE_UNAVAILABLE && $this->config->getSystemValue('debug', false)) { + } catch (ClientException $e) { + // Server responded with 4xx (400 Bad Request mostlikely) + $response = $e->getResponse(); + } catch (ServerException $e) { + // Server responded with 5xx + $response = $e->getResponse(); $body = $response->getBody(); + $error = \is_string($body) ? $body : ('no reason given (' . $response->getStatusCode() . ')'); + $this->log->debug('Could not send notification to push server [{url}]: {error}',[ - 'error' => \is_string($body) ? $body : 'no reason given', + 'error' => $error, 'url' => $proxyServer, 'app' => 'notifications', ]); + + $this->printInfo('Could not send notification to push server [' . $proxyServer . ']: ' . $error); + continue; + } catch (\Exception $e) { + $this->log->logException($e, [ + 'app' => 'notifications', + 'level' => ILogger::ERROR, + ]); + + $error = $e->getMessage() ?: 'no reason given'; + $this->printInfo('Could not send notification to push server [' . get_class($e) . ']: ' . $error); continue; } + $status = $response->getStatusCode(); $body = $response->getBody(); $bodyData = json_decode($body, true); - if ($status !== Http::STATUS_OK) { + + if (is_array($bodyData) && isset($bodyData['unknown'], $bodyData['failed']) && is_array($bodyData['unknown'])) { + foreach ($bodyData['unknown'] as $unknownDevice) { + $this->printInfo('Deleting device because it is unknown by the push server: ' . $unknownDevice); + $this->deletePushTokenByDeviceIdentifier($unknownDevice); + } + + if ($bodyData['failed'] !== 0) { + $this->printInfo('Push notification sent, but ' . $bodyData['failed'] . ' failed'); + } else { + $this->printInfo('Push notification sent successfully'); + } + } elseif ($status !== Http::STATUS_OK) { $error = \is_string($body) && $bodyData === null ? $body : 'no reason given'; $this->printInfo('Could not send notification to push server [' . $proxyServer . ']: ' . $error); - $this->log->error('Could not send notification to push server [{url}]: {error}', [ + $this->log->warning('Could not send notification to push server [{url}]: {error}', [ 'error' => $error, 'url' => $proxyServer, 'app' => 'notifications', ]); } else { - $this->printInfo('Push notification sent'); - } - - if (is_array($bodyData) && !empty($bodyData['unknown']) && is_array($bodyData['unknown'])) { - foreach ($bodyData['unknown'] as $unknownDevice) { - $this->printInfo('Deleting device because it is unknown by the push server: ' . $unknownDevice); - $this->deletePushTokenByDeviceIdentifier($unknownDevice); - } + $error = \is_string($body) && $bodyData === null ? $body : 'no reason given'; + $this->printInfo('Push notification sent but response was not parsable, using an outdated push proxy? [' . $proxyServer . ']: ' . $error); + $this->log->info('Push notification sent but response was not parsable, using an outdated push proxy? [{url}]: {error}', [ + 'error' => $error, + 'url' => $proxyServer, + 'app' => 'notifications', + ]); } } } -- cgit v1.2.3 From 3c2a74fa0680a3ec6943b0a65755bf1df13c1b52 Mon Sep 17 00:00:00 2001 From: Joas Schilling Date: Wed, 30 Sep 2020 09:17:42 +0200 Subject: Fix unit tests Signed-off-by: Joas Schilling --- tests/Unit/PushTest.php | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/tests/Unit/PushTest.php b/tests/Unit/PushTest.php index be6c36d..f14599f 100644 --- a/tests/Unit/PushTest.php +++ b/tests/Unit/PushTest.php @@ -511,7 +511,7 @@ class PushTest extends TestCase { ->method('logException') ->with($e, [ 'app' => 'notifications', - 'level' => ILogger::WARN, + 'level' => ILogger::ERROR, ]); /** @var IResponse|MockObject $response1 */ @@ -522,6 +522,9 @@ class PushTest extends TestCase { $response1->expects($this->once()) ->method('getBody') ->willReturn(null); + $e = $this->createMock(ClientException::class); + $e->method('getResponse') + ->willReturn($response1); $client->expects($this->at(1)) ->method('post') ->with('badrequest/notifications', [ @@ -532,7 +535,7 @@ class PushTest extends TestCase { ->willReturn($response1); $this->logger->expects($this->at(1)) - ->method('error') + ->method('warning') ->with('Could not send notification to push server [{url}]: {error}', [ 'error' => 'no reason given', 'url' => 'badrequest', @@ -541,12 +544,12 @@ class PushTest extends TestCase { /** @var IResponse|MockObject $response1 */ $response2 = $this->createMock(IResponse::class); - $response2->expects($this->once()) - ->method('getStatusCode') - ->willReturn(Http::STATUS_SERVICE_UNAVAILABLE); $response2->expects($this->once()) ->method('getBody') ->willReturn('Maintenance'); + $e = $this->createMock(ServerException::class); + $e->method('getResponse') + ->willReturn($response2); $client->expects($this->at(2)) ->method('post') ->with('unavailable/notifications', [ @@ -556,7 +559,7 @@ class PushTest extends TestCase { ]) ->willReturn($response2); - $this->logger->expects($isDebug ? $this->at(2) : $this->never()) + $this->logger->expects($this->at(2)) ->method('debug') ->with('Could not send notification to push server [{url}]: {error}', [ 'error' => 'Maintenance', -- cgit v1.2.3 From 0e66c054cb851bb198e51dafd780d5f70941f566 Mon Sep 17 00:00:00 2001 From: Joas Schilling Date: Wed, 30 Sep 2020 09:40:25 +0200 Subject: Add test for the new code Signed-off-by: Joas Schilling --- lib/Push.php | 12 +++++++----- tests/Unit/PushTest.php | 39 ++++++++++++++++++++++++++++++++++++--- 2 files changed, 43 insertions(+), 8 deletions(-) diff --git a/lib/Push.php b/lib/Push.php index ce86c06..806f1a6 100644 --- a/lib/Push.php +++ b/lib/Push.php @@ -272,7 +272,7 @@ class Push { $body = $response->getBody(); $error = \is_string($body) ? $body : ('no reason given (' . $response->getStatusCode() . ')'); - $this->log->debug('Could not send notification to push server [{url}]: {error}',[ + $this->log->debug('Could not send notification to push server [{url}]: {error}', [ 'error' => $error, 'url' => $proxyServer, 'app' => 'notifications', @@ -295,10 +295,12 @@ class Push { $body = $response->getBody(); $bodyData = json_decode($body, true); - if (is_array($bodyData) && isset($bodyData['unknown'], $bodyData['failed']) && is_array($bodyData['unknown'])) { - foreach ($bodyData['unknown'] as $unknownDevice) { - $this->printInfo('Deleting device because it is unknown by the push server: ' . $unknownDevice); - $this->deletePushTokenByDeviceIdentifier($unknownDevice); + if (is_array($bodyData) && isset($bodyData['unknown'], $bodyData['failed'])) { + if (is_array($bodyData['unknown'])) { + foreach ($bodyData['unknown'] as $unknownDevice) { + $this->printInfo('Deleting device because it is unknown by the push server: ' . $unknownDevice); + $this->deletePushTokenByDeviceIdentifier($unknownDevice); + } } if ($bodyData['failed'] !== 0) { diff --git a/tests/Unit/PushTest.php b/tests/Unit/PushTest.php index f14599f..c0a725c 100644 --- a/tests/Unit/PushTest.php +++ b/tests/Unit/PushTest.php @@ -403,7 +403,7 @@ class PushTest extends TestCase { * @param bool $isDebug */ public function testPushToDeviceSending($isDebug) { - $push = $this->getPush(['getDevicesForUser', 'encryptAndSign', 'deletePushToken', 'validateToken']); + $push = $this->getPush(['getDevicesForUser', 'encryptAndSign', 'deletePushToken', 'validateToken', 'deletePushTokenByDeviceIdentifier']); /** @var INotification|MockObject $notification */ $notification = $this->createMock(INotification::class); @@ -447,6 +447,11 @@ class PushTest extends TestCase { 'token' => 64, 'apptype' => 'other', ], + [ + 'proxyserver' => 'badrequest-with-devices', + 'token' => 128, + 'apptype' => 'other', + ], ]); $this->config->expects($this->exactly(2)) @@ -474,11 +479,11 @@ class PushTest extends TestCase { ->with($user) ->willReturn($key); - $push->expects($this->exactly(5)) + $push->expects($this->exactly(6)) ->method('validateToken') ->willReturn(true); - $push->expects($this->exactly(5)) + $push->expects($this->exactly(6)) ->method('encryptAndSign') ->willReturn(['Payload']); @@ -581,6 +586,34 @@ class PushTest extends TestCase { ]) ->willReturn($response3); + /** @var IResponse|MockObject $response1 */ + $response4 = $this->createMock(IResponse::class); + $response4->expects($this->once()) + ->method('getStatusCode') + ->willReturn(Http::STATUS_BAD_REQUEST); + $response4->expects($this->once()) + ->method('getBody') + ->willReturn(json_encode([ + 'failed' => 1, + 'unknown' => [ + '123456' + ] + ])); + $e = $this->createMock(ClientException::class); + $e->method('getResponse') + ->willReturn($response4); + $client->expects($this->at(4)) + ->method('post') + ->with('badrequest-with-devices/notifications', [ + 'body' => [ + 'notifications' => ['["Payload"]'], + ], + ]) + ->willThrowException($e); + + $push->method('deletePushTokenByDeviceIdentifier') + ->with('123456'); + $push->pushToDevice(207787, $notification); } -- cgit v1.2.3 From 938c005d1a6d87a31060d164ff7dbe3edf72510a Mon Sep 17 00:00:00 2001 From: Joas Schilling Date: Wed, 30 Sep 2020 09:41:22 +0200 Subject: Add a comment for the array check Signed-off-by: Joas Schilling --- lib/Push.php | 3 +++ tests/Unit/PushTest.php | 43 ++++++++++++++++++++++--------------------- 2 files changed, 25 insertions(+), 21 deletions(-) diff --git a/lib/Push.php b/lib/Push.php index 806f1a6..c3f6405 100644 --- a/lib/Push.php +++ b/lib/Push.php @@ -22,6 +22,8 @@ namespace OCA\Notifications; +use GuzzleHttp\Exception\ClientException; +use GuzzleHttp\Exception\ServerException; use OC\Authentication\Exceptions\InvalidTokenException; use OC\Authentication\Token\IProvider; use OC\Security\IdentityProof\Key; @@ -297,6 +299,7 @@ class Push { if (is_array($bodyData) && isset($bodyData['unknown'], $bodyData['failed'])) { if (is_array($bodyData['unknown'])) { + // Proxy returns null when the array is empty foreach ($bodyData['unknown'] as $unknownDevice) { $this->printInfo('Deleting device because it is unknown by the push server: ' . $unknownDevice); $this->deletePushTokenByDeviceIdentifier($unknownDevice); diff --git a/tests/Unit/PushTest.php b/tests/Unit/PushTest.php index c0a725c..f05be9c 100644 --- a/tests/Unit/PushTest.php +++ b/tests/Unit/PushTest.php @@ -23,6 +23,8 @@ namespace OCA\Notifications\Tests\Unit; +use GuzzleHttp\Exception\ClientException; +use GuzzleHttp\Exception\ServerException; use OC\Authentication\Exceptions\InvalidTokenException; use OC\Authentication\Token\IProvider; use OC\Security\IdentityProof\Key; @@ -407,7 +409,7 @@ class PushTest extends TestCase { /** @var INotification|MockObject $notification */ $notification = $this->createMock(INotification::class); - $notification->expects($this->exactly(3)) + $notification ->method('getUser') ->willReturn('valid'); @@ -454,10 +456,9 @@ class PushTest extends TestCase { ], ]); - $this->config->expects($this->exactly(2)) + $this->config->expects($this->exactly(1)) ->method('getSystemValue') ->willReturnMap([ - ['debug', false, $isDebug], ['force_language', false, false], ]); @@ -506,10 +507,10 @@ class PushTest extends TestCase { $client->expects($this->at(0)) ->method('post') ->with('proxyserver1/notifications', [ - 'body' => [ - 'notifications' => ['["Payload"]', '["Payload"]'], - ], - ]) + 'body' => [ + 'notifications' => ['["Payload"]', '["Payload"]'], + ], + ]) ->willThrowException($e); $this->logger->expects($this->at(0)) @@ -533,11 +534,11 @@ class PushTest extends TestCase { $client->expects($this->at(1)) ->method('post') ->with('badrequest/notifications', [ - 'body' => [ - 'notifications' => ['["Payload"]'], - ], - ]) - ->willReturn($response1); + 'body' => [ + 'notifications' => ['["Payload"]'], + ], + ]) + ->willThrowException($e); $this->logger->expects($this->at(1)) ->method('warning') @@ -558,11 +559,11 @@ class PushTest extends TestCase { $client->expects($this->at(2)) ->method('post') ->with('unavailable/notifications', [ - 'body' => [ - 'notifications' => ['["Payload"]'], - ], - ]) - ->willReturn($response2); + 'body' => [ + 'notifications' => ['["Payload"]'], + ], + ]) + ->willThrowException($e); $this->logger->expects($this->at(2)) ->method('debug') @@ -580,10 +581,10 @@ class PushTest extends TestCase { $client->expects($this->at(3)) ->method('post') ->with('ok/notifications', [ - 'body' => [ - 'notifications' => ['["Payload"]'], - ], - ]) + 'body' => [ + 'notifications' => ['["Payload"]'], + ], + ]) ->willReturn($response3); /** @var IResponse|MockObject $response1 */ -- cgit v1.2.3