[horde] Sending HTTP 401 Unauthorized header response

[Arjen de Korte]

Citeren Michael J Rubinsky <mrubinsk at horde.org>:

> Quoting Arjen de Korte <build+horde at de-korte.org>:
>
>> Citeren Arjen de Korte <build+horde at de-korte.org>:
>>
>>> Citeren Arjen de Korte <build+horde at de-korte.org>:
>>>
>>>> Possibly more log spam:
>>>>
>>>> 2019-01-04T13:23:44+01:00 ERR: horde Sending HTTP 401  
>>>> Unauthorized header response. [pid 1949 on line 126 of  
>>>> "/usr/share/php7/PEAR/Horde/Rpc/ActiveSync.php"]
>>>>
>>>> Dumping $serverVars just a few lines before this line, it looks  
>>>> like the client attempts to authenticate with type "Bearer" but  
>>>> there is no token. I also see requests where the same client is  
>>>> using Basic authentication with a base64 encoded username and  
>>>> password, which works fine. The client in question is the  
>>>> built-in Windows 10 Mail and synchronizes as usual.
>>>>
>>>> I've removed the account and recreated it, but the problem remains.
>>>
>>> It occurs with multiple accounts, all using the Windows 10 Mail  
>>> client. When logging the $serverVars['HTTP_AUTHORIZATION']  
>>> variable, they seem to come in pairs:
>>>
>>>   2019-01-04T19:24:10+01:00 DEBUG: Variable information:
>>>   string(50) "Basic XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX=="
>>>
>>>   Backtrace:
>>>   1. Horde_Rpc_ActiveSync->getResponse() /srv/www/htdocs/horde/rpc.php:160
>>>   2. Horde::debug() /usr/share/php7/PEAR/Horde/Rpc/ActiveSync.php:120
>>>
>>>   2019-01-04T19:24:26+01:00 DEBUG: Variable information:
>>>   string(6) "Bearer"
>>>
>>>   Backtrace:
>>>   1. Horde_Rpc_ActiveSync->getResponse() /srv/www/htdocs/horde/rpc.php:160
>>>   2. Horde::debug() /usr/share/php7/PEAR/Horde/Rpc/ActiveSync.php:120
>>>
>>> Could it somehow be that no token is sent from the server to the  
>>> client? Can I somehow log the token?
>>
>> These are weird requests. I enabled the forensics log of Apache and  
>> this is what it came up with for these packets:
>>
>> +24647:5c308a50:0|OPTIONS  
>> /Microsoft-Server-ActiveSync?User=xxxx&DeviceId=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX&DeviceType=WindowsMail HTTP/1.1|Cache-Control:no-cache|Connection:Keep-Alive|Pragma:no-cache|Authorization:Basic  
>> XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX=|User-Agent:MSFT-WIN-3/10.0.17134|MS-ASProtocolVersion:14.1|Host:mail.example.com|Cookie:PHPSESSID=XXXXXXXXXXXXXXXXXXXXXXXXXX
>> +24647:5c308b42:5|OPTIONS /Microsoft-Server-ActiveSync  
>> HTTP/1.1|Cache-Control:no-cache|Connection:Keep-Alive|Pragma:no-cache|Authorization:Bearer|User-Agent:MSFT-WIN-3/10.0.17134|MS-ASProtocolVersion:2.5|Host:mail.example.com
>>
>> The first is what I expect for ActiveSync connections, but the  
>> second looks like some kind of probe for the connectivity to the  
>> EAS server, rather than an attempt to actively exchange data. Look  
>> at the difference in the ASProtocolVersion and the absence of any  
>> identifying data.
>
> This looks like the initial, empty Bearer challenge that Outlook can  
> send when initiating OAuth authenticatie. This is used when the  
> client is enabled for Hybrid Modern Authentication. This is used  
> when Outlook is connecting with Office 365/Azure AD in combination  
> with a on-premise Exchange server. No clue why the client would send  
> those frequently.

Probably because it is not getting an expected reply, although I have  
no idea what this would be. It looks like the present 401 is not the  
right one, the clients send this quite frequently (a couple of times  
per hour per client).

> If you are seeing those often, it sounds like a client bug.