[horde] Sending HTTP 401 Unauthorized header response
Michael J Rubinsky
mrubinsk at horde.org
Mon Jan 7 13:57:15 UTC 2019
Quoting Arjen de Korte <build+horde at de-korte.org>:
> Citeren Arjen de Korte <build+horde at de-korte.org>:
>
>> 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.
>
> After a bit more logging, I now see two distinct cases where an
> empty Bearer challenge is used:
>
> +24860:5c30fa08:bd|POST /AutoDiscover/AutoDiscover.xml
> HTTP/2.0|Accept:*/*|Authorization:Bearer|User-Agent:microsoft.windowscommunicationsapps|Content-Type:text/xml|Accept-Language:nl-NL,nl;q=0.5|Accept-Encoding:gzip, deflate,
> br|Content-Length:356|Cache-Control:no-cache|Host:example.com
>
> and
>
> +24646:5c324a0e:284|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:example.com
>
> The first of these two is sent only when setting up a new EAS
> account on a client, so I don't see that one very often. The second
> is send *much* more frequently (a couple of times per hour per
> client) and only for clients on Windows 10 (I don't have users with
> other Windows versions) using the built-in Mail-app. None of them is
> configured to use/require Modern Authentication.
I researched this for a few hours yesterday, and I don't see anything
else we could be sending back to the client to indicate we don't
support Modern Authentication. My guess is that MS Mail is either
broken, or just behaves inefficiently, trying Modern Authentication
too frequently. The only other thing I can think of is that there is
some undocumented value in the AUTODISCOVER response schema: We are
sending a 401, which in addition to being the correct HTTP error code,
MS explicitly documents in MS-ASHTTP 3.1.5.2.1 as indicating that the
client should send an AUTODISCOVER request to the server. There is
nothing in the protocol documentation which states that AUTODISCOVER
returns any information related to authentication, other than the
username and hostname.
I also find it funny that the ASProtocolVersion is set to 2.5 in the
OPTIONS request. While the Bearer token isn't technically a part of
the EAS protocol, there was no support for this back when the current
EAS version was 2.5...I'm assuming you have configured a recent
version in your horde config and see this more recent version as the
supported version in other "Normal" requests?
I do know that when initially provisioning desktop Outlook a request
is actually sent to some MS Office 365 server, which then queries your
server's Autodiscover endpoint. There is some undocumented (at least I
couldn't find any) response schema that is expected by MS' server
that, when missing, causes autodiscovery to fail and (unless a
registry tweak is made) prevents provisioning desktop Outlook to
Horde. Perhaps this is something related?
--
mike
The Horde Project
http://www.horde.org
https://www.facebook.com/hordeproject
https://www.twitter.com/hordeproject
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-keys
Size: 9272 bytes
Desc: PGP Public Key
URL: <https://lists.horde.org/archives/horde/attachments/20190107/21d2eb98/attachment.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 821 bytes
Desc: PGP Digital Signature
URL: <https://lists.horde.org/archives/horde/attachments/20190107/21d2eb98/attachment-0001.bin>
More information about the horde
mailing list