2

This code sometimes works, but frequently runs for ~20s then fails with the "503 Service Unavailable" message when I call getPage(). The authentication/token request seems to be working fine.

I can't seem to identify any pattern of when it fails/succeeds. I don't believe it's a throttling error, as there is no "Retry-After" header returned, and the script only runs once per day at night with <200 records returned. I've also tried removing the $filter and changing parameter order as described here, with no clear benefit.

Can someone please help find the cause here? Happy to share any additional info. Any help is much appreciated, thanks!

<?php
define('DEBUG', true);
session_start();

// set config vars
$ms_url_base = "https://login.microsoftonline.com/d3523db7-f84a-4a24-a815-cd4ba4691c9c";
$ms_client_id = '<client id>';
$ms_redirect_uri = "https://example.com/path";
$ms_scope = "calendars.readwrite user.read";
$ms_client_secret = '<secret>';
$ms_auth_endpoint = '/oauth2/v2.0/authorize';
$ms_token_endpoint = '/oauth2/v2.0/token';
$query_numdays = 100;
if (DEBUG) error_reporting(E_ALL);
date_default_timezone_set("America/Detroit");

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

use Microsoft\Graph\Graph;
use Microsoft\Graph\Model;
class EventMod extends \Microsoft\Graph\Model\Event {
    // custom functions here 

    public function getNextLink() {
        parent::getNextLink();
    }
}
class ResponseMod extends \Microsoft\Graph\Http\GraphResponse {}

// authorization
$provider = new Stevenmaguire\OAuth2\Client\Provider\Microsoft([
    'clientId'                  => $ms_client_id,
    'clientSecret'              => $ms_client_secret,
    'redirectUri'               => $ms_redirect_uri,
    'urlAuthorize'              => $ms_url_base.$ms_auth_endpoint,
    'urlAccessToken'            => $ms_url_base.$ms_token_endpoint,
    'urlResourceOwnerDetails'   => 'https://graph.microsoft.com/v2.0/me',
]);

if (!isset($_GET['code'])) {
    $options = ['scope' => $ms_scope, 'aud' => 'Graph'];
    $authUrl = $provider->getAuthorizationUrl($options);
    $_SESSION['oauth2state'] = $provider->getState();
    header('Location: '.$authUrl);
    exit;

} elseif (empty($_GET['state']) || ($_GET['state'] !== $_SESSION['oauth2state'])) {
    unset($_SESSION['oauth2state']);
    exit('Invalid state');
} else {
    try {
        $token = $provider->getAccessToken('authorization_code', ['code' => $_GET['code']]);
    } catch (League\OAuth2\Client\Provider\Exception\IdentityProviderException $e) {
        exit ("Get access token exception: ".$e->getMessage());
    }

    if (DEBUG) {
        echo 'Access Token: ' . $token->getToken() . "<p>";
        echo 'Refresh Token: ' . $token->getRefreshToken() . "<p>";
        echo 'Expired in: ' . $token->getExpires() . "<p>";
        echo 'Already expired? ' . ($token->hasExpired() ? 'expired' : 'not expired') . "<p>";
    }

    // start calendar query
    $start=new DateTimeImmutable("yesterday 0:0:1");
    $end = $start->add(new DateInterval("P".$query_numdays."D"));

    $url='/me/calendarview'
        .'?startdatetime='.$start->format('c')
        .'&enddatetime='.$end->format('c')
        .'&$filter=isOrganizer+eq+false'
        .'&$select=subject,responseStatus,start,categories'
        .'&$orderby=start/dateTime';

    $graph = new Graph;
    $graph->setAccessToken($token->getToken());
    $data = array();
    try {
        $iterator = $graph->createCollectionRequest("GET", $url)
                    ->setReturnType(EventMod::class)
                    ->addHeaders(["Prefer" => 'outlook.timezone="America/Detroit"'])
                    ->setPageSize(25);
        do {
            $page = $iterator->getPage(); /*************** THIS IS WHERE THE EXCEPTION HAPPENS ************/
            if (DEBUG) echo "<pre>".print_r($page, true)."</pre>";
            $data = array_merge($data, $page);
        } while (!$iterator->isEnd());
    } 
    catch (\Microsoft\Graph\Exception\GraphException $e) {
        if (DEBUG) echo "GraphException Message: ".$e->getMessage();
        exit;
    }
    catch (Exception $e) {
        if (DEBUG) echo "Unk Exception getting data: ".$e->getMessage();
        exit;
    }

    if (DEBUG) print_r($data);
}
?>

composer.json

{
    "require": {
        "microsoft/microsoft-graph": "^1.29",
        "stevenmaguire/oauth2-microsoft": "^2.2"
    }
}
Marc LaFleur
  • 31,987
  • 4
  • 37
  • 63
Nick
  • 85
  • 7
  • I see that you're using Pagination, thats good. In addition to that, just to isolate the issue out of your code, try Microsoft Graph explorer or POSTMAN with the above exact flow/API call and see if you can repro the issue. – Dev Apr 28 '21 at 04:30
  • If i am not wrong, think the issue happens you're trying to use complex odata query above - i see that you're using mix of filter(filter the results), select(columns), orderby(ordering them). You may want to play around with the combinations or i would start adding one by one and see till i can repro the issue. – Dev Apr 28 '21 at 04:32
  • Thanks for checking @Dev! I reduced it to just the start and end time, removing the select, filter and orderby clause. Still get 503s. Will try graph explorer. – Nick Apr 28 '21 at 14:34
  • sure @Nick let me know how it goes. – Dev Apr 29 '21 at 02:41
  • Same result on Graph explorer - rarely, I get the expected results instantly. More often "Service Unavailable - 503 - 109321ms" – Nick Apr 29 '21 at 04:00
  • Interesting. I tried repro the issue at my end (against my M365 mailbox) and it worked for me (with limited records around 200). Please update the detailed error that you received (timestamp, requestid) as well. – Dev Apr 29 '21 at 05:09
  • edited response: reasonPhrase => Service Unavailable statusCode => 503 headers => Date => Thu, 29 Apr 2021 15:20:04 GMT Transfer-Encoding => chunked Strict-Transport-Security => max-age=31536000 request-id => b9ef0347-19ce-485b-9fe3-bff0dd5d404f client-request-id => b9ef0347-19ce-485b-9fe3-bff0dd5d404f x-ms-ags-diagnostic => {"ServerInfo":{"DataCenter":"North Central US","Slice":"E","Ring":"3","ScaleUnit":"004","RoleInstance":"CH01EPF00003ED2"} – Nick Apr 29 '21 at 15:26
  • Thanks for the update @Nick and updating the answer. I played with your above API call and i ended up noticing the issue - in the case of having bigger larger dates and lot of data at my end. It tells me that the failure is due to the client timeout. We need to understand that Calendar view is an expensive operation that too when you deal with calendars and filters added to it. So i went ahead in this scenario, reduce/minimize time window for calendar view by client so smaller segments of time are scanned for matching calendar events. It helped me to get the records as i expected. – Dev Apr 30 '21 at 08:18

2 Answers2

2

I played with your above API call and i ended up noticing the issue - in the case of having bigger larger dates and lot of data at my end (not with smaller time window or less records). It tells me that the failure is due to the client timeout. We need to understand that Calendar view is an expensive operation that too when you deal with calendars and filters added to it. So i went ahead in this scenario, reduce/minimize time window for calendar view by client so smaller segments of time are scanned for matching calendar events. It helped me to get the records as i expected and make use of effective usage of Calendarview API call too.

Dev
  • 2,428
  • 2
  • 14
  • 15
  • Not sure if it's a client timeout. At least, not in my code. The php timeout was set to 60 seconds and the 503 error was returned by the server after ~20s. I tried passing setTimeout(100) to createCollectionRequest() with no change. Perhaps the timeout happens at the SDK level? Also smaller segments of time would not make a difference, because the error was traced to one single event. – Nick May 01 '21 at 02:08
  • if its related to single event then i would just point it out as the point of contact which leads to the issue, nor the API or SDK. Good analysis/research so far!! – Dev May 01 '21 at 05:03
0

Apparently the issue was not in the code at all. I discovered that the 503 error was thrown only when a specific date's events were being read by the API. One of the events was rather large and I deleted it; after this the script works well.

This particular event has 16536 attendees listed, which I believe was the source of the error. Still unexplained is why the error was intermittent. I was eventually able to get graph explorer to successfully read the event, so perhaps the bug is in the Microsoft Graph SDK for PHP. I will post there to see if the devs want to capture this error condition.

Nick
  • 85
  • 7
  • 1
    oh wow, 16536 attendees listed in a particular event - no wonder why the client is timing out and you ended up getting HTTP 503. As i said above you're performing an expensive operation(Calendarview) and that too with calendars and filters added leading to this issue. Try the above suggestions to see if it helps. Also let me move to answer, so it can be useful to others as well (if it suits their scenario). – Dev Apr 30 '21 at 08:24
  • For future reference, this does not seem to be a client timeout issue - the server returns the 503 error much before the PHP script times out, and passing setTimeout(100) to createCollectionRequest() had no effect. Perhaps an issue with msgraph-sdk-php. Investigating. – Nick May 01 '21 at 17:11
  • Got it. If you confirm its an issue with SDK, i would suggest you to file the issue at the MS Graph SDK for PHP repo - so that it can be fixed. Before doing so, just make sure you repro the issue with the latest SDK builds. – Dev May 03 '21 at 15:50