Summary | ActiveSync: Unknown sync options cause infinite loop |
Queue | Synchronization |
Queue Version | Git master |
Type | Bug |
State | Resolved |
Priority | 1. Low |
Owners | mrubinsk (at) horde (dot) org |
Requester | hannes.brunssen (at) ewetel (dot) de |
Created | 07/30/2014 (3991 days ago) |
Due | |
Updated | 08/12/2014 (3978 days ago) |
Assigned | 08/07/2014 (3983 days ago) |
Resolved | 08/11/2014 (3979 days ago) |
Github Issue Link | |
Github Pull Request | |
Milestone | |
Patch | No |
Summary ⇒ C
State ⇒ Resolved
reopen if additional issues are found.
State ⇒ Feedback
that it still works for you?
...wish I could find a client that issued these options :/
commit b762a16ef009aca70fe8158aca93d5cc5891d06a
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Thu Aug 7 11:57:43 2014 -0400
Next attempt at
Bug: 13405.../lib/Horde/ActiveSync/Request/Sync.php | 26 +++++++++----------
1 files changed, 12 insertions(+), 14 deletions(-)
http://github.com/horde/horde/commit/b762a16ef009aca70fe8158aca93d5cc5891d06a
State ⇒ Assigned
empty tag is encountered since these are essentially EN_TYPE_STARTTAGs
with no matching EN_TYPE_ENDTAGs.
I'll have to look at this further.
New Attachment: eas-loop.patch
after the first end tag:
2014-08-07T13:32:51+02:00 DEBUG: [49154] I <Options>
2014-08-07T13:32:51+02:00 DEBUG: [49154] I <WindowsLive:Annotations>
2014-08-07T13:32:51+02:00 DEBUG: [49154] I <WindowsLive:Annotation>
2014-08-07T13:32:51+02:00 DEBUG: [49154] I <WindowsLive:Name>
2014-08-07T13:32:51+02:00 DEBUG: [49154] I CID
2014-08-07T13:32:51+02:00 DEBUG: [49154] I </WindowsLive:Name>
2014-08-07T13:32:51+02:00 DEBUG: [49154] I
</WindowsLive:Annotation> <-- expected </Options>
2014-08-07T13:32:51+02:00 DEBUG: [49154] I
<WindowsLive:Annotation> <-- expected </Folder>
2014-08-07T13:32:51+02:00 ERR: [49154] Unmatched end tag:
2014-08-07T13:32:51+02:00 ERR: Array
(
[1] => 1
[2] => WindowsLive:Annotation
[4] => 1
)
I added a patch that skips all open tags and only fails on invalid data.
commit 0be97b738c5b2e23400fb0df7357da3a5e0aab72
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Wed Aug 6 16:31:12 2014 -0400
Read in any unsupported OPTIONS data.
See
Bug: 13405.../lib/Horde/ActiveSync/Request/Sync.php | 41
++++++++++++++++----
1 files changed, 33 insertions(+), 8 deletions(-)
http://github.com/horde/horde/commit/0be97b738c5b2e23400fb0df7357da3a5e0aab72
commit 63e6c0d2426a198737e8d2c8d5997b46c5067f22
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Wed Aug 6 16:30:16 2014 -0400
Add the Windows Live codepage.
See
Bug: 13405.../ActiveSync/lib/Horde/ActiveSync/Wbxml.php | 10 ++++++++++
1 files changed, 10 insertions(+), 0 deletions(-)
http://github.com/horde/horde/commit/63e6c0d2426a198737e8d2c8d5997b46c5067f22
before in my research.
header because it contains live credentials and I can't reproduce the
problem myself.
The parser fails at the switch to code page 0xFE, which is not
documented in MS-ASWBXML (Exchange ActiveSync: WAP Binary XML (WBXML)
Algorithm) and even wireshark can't decode this part. The only
reference I found is the following page, but it seems the links to the
documentation are dead:
http://social.msdn.microsoft.com/Forums/de-DE/75562e26-158c-45d3-b114-b2b82928c3a7/undocumented-activesync-codepage?forum=os_exchangeprotocols
This is the decoded data:
03 01 6a 00
45 <Sync>
5c <Collections>
4f <Collection>
4b <SyncKey>
03 7b 35 33 63 36 34 64 31 61 2d 63 33 32 38 2d 34 38 66 65 2d 62 64
35 36 2d 32 38 62 66 64 35 61 38 63 32 32 66 7d 33 33 00
{53c64d1a-c328-48fe-bd56-28bfd5a8c22f}33
01 </SyncKey>
52 <CollectionId>
03 46 36 64 32 31 39 33 66 32 00 F6d2193f2
01 </CollectionId>
5e <DeletesAsMoves>
03 30 00 0
01 </DeletesAsMoves>
55 <WindowSize>
03 31 30 30 00 100
01 </WindowSize>
01 </Collection>
4f <Collection>
4b <SyncKey>
03 30 00 0
01 </SyncKey>
52 <CollectionId>
03 40 43 61 6c 65 6e 64 61 72 40 00 @Calendar@
01 </CollectionId>
01 </Collection>
4f <Collection>
4b <SyncKey>
03 30 00 0
01 </SyncKey
52 <CollectionId>
40 43 6f 6e 74 61 63 74 73 40 00 @Contacts@
01 </CollectionId>
57 <Options>
00 fe Switch to code page WindowsLive
45 <Annotations>
46 <Annotation>
47 <Name>
03 43 49 44 00 CID
01 </Name>
01 </Annotation>
46 <Annotation>
47 <Name>
03 57 4c 49 44 00 WLID
01 </Name>
01 </Annotation>
46 <Annotation>
47 <Name>
03 54 79 70 65 00 Type
01 </Name>
01 </Annotation>
46 <Annotation>
47 <Name>
03 53 49 44 00 SID
01 </Name>
01 </Annotation>
46 <Annotation>
47 <Name>
03 4f 49 44 00 OID
01 </Name>
01 </Annotation>
46 <Annotation>
47 <Name>
03 55 73 65 72 54 69 6c 65 55 72 6c 00 UserTileUrl
01 </Name>
01 </Annotation>
46 <Annotation>
47 <Name>
03 55 73 65 72 54 69 6c 65 48 61 73 68 00 UserTileHash
01 </Name>
01 </Annotation>
01 </Annotations>
01 </Options>
01 </Collection>
00 00 Switch to code page AirSync
4f <Collection>
4b <SyncKey>
03 30 00 0
01 </SyncKey>
52 <CollectionId>
03 46 61 32 61 31 31 39 31 37 00 Fa2a11917
01 </CollectionId>
01 </Collection>
4f <Collection>
4b <SyncKey>
03 30 00 0
01 </SyncKey>
52 <CollectionId>
03 46 32 61 36 61 32 36 38 63 00 F2a6a268c
01 </CollectionId>
01 </Collection>
01 </Collections>
55 <WindowSize>
03 31 30 30 00 100
01 </WindowSize>
01 </Sync>
will cause the sync to fail if an invalid OPTIONS value is sent.
commit 1f629bdaa83f2c1e325b76f568578a581101b0fe
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Tue Aug 5 23:57:47 2014 -0400
No harm in allowing this even for EAS <= 12.1
Also, protects against broken clients that may send this before
EAS 12.1 as well. Possibly related to
Bug: 13405.../lib/Horde/ActiveSync/Request/Sync.php | 3 +--
1 files changed, 1 insertions(+), 2 deletions(-)
http://github.com/horde/horde/commit/1f629bdaa83f2c1e325b76f568578a581101b0fe
commit f236c5016629bfdc54542ab98cb84792094b0fa8
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Tue Aug 5 23:56:55 2014 -0400
Protect against infinite loop due to invalid OPTIONS data.
Bug: #13405.../lib/Horde/ActiveSync/Request/Sync.php | 10 ++++++++++
1 files changed, 10 insertions(+), 0 deletions(-)
http://github.com/horde/horde/commit/f236c5016629bfdc54542ab98cb84792094b0fa8
State ⇒ Feedback
number isn't the same as yours. Worked fine.
without the HTTP headers, etc...
New Attachment: eas-loop.pcap
0000 03 01 6a 00 45 5c 4f 4b 03 7b 35 33 63 36 34 64 ..j.E\OK.{53c64d
0010 31 61 2d 63 33 32 38 2d 34 38 66 65 2d 62 64 35 1a-c328-48fe-bd5
0020 36 2d 32 38 62 66 64 35 61 38 63 32 32 66 7d 33 6-28bfd5a8c22f}3
0030 33 00 01 52 03 46 36 64 32 31 39 33 66 32 00 01 3..R.F6d2193f2..
0040 5e 03 30 00 01 55 03 31 30 30 00 01 01 4f 4b 03 ^.0..U.100...OK.
0050 30 00 01 52 03 40 43 61 6c 65 6e 64 61 72 40 00 0..R.@Calendar@.
0060 01 01 4f 4b 03 30 00 01 52 03 40 43 6f 6e 74 61 ..OK.0..R.@Conta
0070 63 74 73 40 00 01 57 00 fe 45 46 47 03 43 49 44 cts@..W..EFG.CID
0080 00 01 01 46 47 03 57 4c 49 44 00 01 01 46 47 03 ...FG.WLID...FG.
0090 54 79 70 65 00 01 01 46 47 03 53 49 44 00 01 01 Type...FG.SID...
00a0 46 47 03 4f 49 44 00 01 01 46 47 03 55 73 65 72 FG.OID...FG.User
00b0 54 69 6c 65 55 72 6c 00 01 01 46 47 03 55 73 65 TileUrl...FG.Use
00c0 72 54 69 6c 65 48 61 73 68 00 01 01 01 01 01 00 rTileHash.......
00d0 00 4f 4b 03 30 00 01 52 03 46 61 32 61 31 31 39 .OK.0..R.Fa2a119
00e0 31 37 00 01 01 4f 4b 03 30 00 01 52 03 46 32 61 17...OK.0..R.F2a
00f0 36 61 32 36 38 63 00 01 01 01 55 03 31 30 30 00 6a268c....U.100.
0100 01 01 ..
Assigned to Michael Rubinsky
State ⇒ Assigned
Regardless, it would be very helpful if you could provide a trace so I
can ensure that it's not a valid OPTIONS value we are not handling
correctly.
Priority ⇒ 1. Low
State ⇒ Unconfirmed
New Attachment: aes-loop.log
Patch ⇒ No
Milestone ⇒
Queue ⇒ Synchronization
Summary ⇒ ActiveSync: Unknown sync options cause infinite loop
Type ⇒ Bug
In the last few days we had several webserver processes caught in an
infinite loop, because a client sent an unknown sync option. These are
the last lines, the full log is attached:
2014-07-29T14:52:51+02:00 DEBUG: [21666] I <Folder>
2014-07-29T14:52:51+02:00 DEBUG: [21666] I <SyncKey>
2014-07-29T14:52:51+02:00 DEBUG: [21666] I 0
2014-07-29T14:52:51+02:00 DEBUG: [21666] I </SyncKey>
2014-07-29T14:52:51+02:00 DEBUG: [21666] I <FolderId>
2014-07-29T14:52:51+02:00 DEBUG: [21666] I @Contacts@
2014-07-29T14:52:51+02:00 DEBUG: [21666] I </FolderId>
2014-07-29T14:52:51+02:00 DEBUG: [21666] I <Options>
2014-07-29T14:52:51+02:00 DEBUG: [21666] I <>
The loop is in Horde_ActiveSync_Request_Sync::_parseSyncOptions, line 1090.
I can try to capture the traffic in the next days if you are
interested, but he is currently not online. The user agent is
WindowsMail/17.5.9600.20498.