Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

vdirsyncer fails to sync due to double URL encoding #491

Closed
sboehringer opened this issue Aug 19, 2016 · 16 comments
Closed

vdirsyncer fails to sync due to double URL encoding #491

sboehringer opened this issue Aug 19, 2016 · 16 comments
Labels
cat: server compat mod: DAV type: bug

Comments

@sboehringer
Copy link

sboehringer commented Aug 19, 2016 •
edited by untitaker

  • Your vdirsyncer version
    vdirsyncer, version 0.11.3
  • If applicable, which server software (and which version) you're using
    DavMail 4.7.2-2427
  • Your Python version
    python --version: Python 2.7.12
    python3 --version: 4.7.2-2427
  • Your operating system
    OpenSuse 13.2
  • Your config file
[general]
# A folder where vdirsyncer can store some metadata about each pair.
status_path = ~/.local/share/vdirsyncer/status/

# CALDAV
[pair my_calendar]
a = my_calendar_local
b = my_calendar_remote
collections = ["from a", "from b"]

# Calendars also have a color property
metadata = ["displayname", "color"]

[storage my_calendar_local]
type = filesystem
path = ~/.local/share/khal/calendars/private
fileext = .ics

[storage my_calendar_remote]
type = caldav
url = http://localhost:10801/users/s.boehringer@lumc.nl/calendar
username = ****
password = *****
  • Use vdirsyncer -vdebug for debug output.
...
error: Unknown error occured for my_calendar/calendar: /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAABHFlNrAAA%3D.EML
error: Use `-vdebug` to see the full traceback.
debug:   File "/usr/lib/python3.4/site-packages/vdirsyncer/cli/tasks.py", line 66, in sync_collection
debug:     force_delete=force_delete
debug:   File "/usr/lib/python3.4/site-packages/vdirsyncer/sync.py", line 216, in sync
debug:     b_info.prepare_idents()
debug:   File "/usr/lib/python3.4/site-packages/vdirsyncer/sync.py", line 124, in prepare_idents
debug:     if prefetch else ()):
debug:   File "/usr/lib/python3.4/site-packages/vdirsyncer/storage/dav.py", line 452, in get_multi
debug:     raise exceptions.NotFoundError(href)
error: 1 out of 2 tasks failed.

The failing URL is partly encoded (trailing %3D). Replacing this with '=' in cadaver prints a proper caldav event.
@untitaker
Copy link
Member

untitaker commented Aug 19, 2016 •
edited

Further above there should be a "Normalized URL from" or "Already normalized". What does it look like?

@sboehringer
Copy link
Author

This would be the line:

debug: Unsafe character: '%3D'
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAAAbI1AAA%3D.EML'

untitaker added a commit that referenced this issue Aug 19, 2016
@untitaker
Remove = from reserved chars
902d914 
See #491
@untitaker
Copy link
Member

This should be fixed in master. If you want, you could try:

virtualenv -p python3 fooenv
. fooenv/bin/activate
pip install git+https://github.com/untitaker/vdirsyncer

Then you have a working development version on ./fooenv/bin/vdirsyncer.

@untitaker
Copy link
Member

0.12.1 is out, please reopen if this bug persists.

@sboehringer
Copy link
Author

Unfortunately, the error persists in version 0.12.1 in identical form.

DavMail is the CalDav server which is a Microsoft Exchange adaptor. As cadaver has a similar problem with showing the events with html-quoted characters, I am wondering whether is is really a DavMail bug. However, I would have a good idea as to how to proceed at the moment.

@untitaker untitaker reopened this Aug 25, 2016
@untitaker
Copy link
Member

Is the forn absolutely identical? In particular the debugging lines about URL normalization (as asked above) interest me.

@sboehringer
Copy link
Author 

debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAABHFlNRAAA%3D.EML'
warning: Skipping identical href: '/users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAABHFlNRAAA%3D.EML'

The already normalized line occurs two times in the debug output. The "@" character is unquoted, the "=" is quoted.
Interestingly, the debug logs of DavMail do not show an access attempt to the event above. No errors are shown at all. This is different from cadaver that triggers errors in the DavMail server. Finally, Thunderbird works fine. Taken together, I would rather tend to assume an independent bug in vdirsync.

@sboehringer
Copy link
Author

Here is the davmail log from DavMail as given for a Thunderbird transaction (it is not the same event as I could not identify it). The EML-resources seem to be recurrent events. Thunderbird has quoted the "@" also.

Date:           Thu Aug 25 17:04:21 CEST 2016 (1472137461367)
Thread:     CaldavConnection-55185
Message #:  2
Level:      DEBUG
NDC:            
Category:   davmail
Message:        < PUT /users/s.boehringer%40lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HIAAA%3D.EML HTTP/1.1
Location:   davmail.ui.tray.DavGatewayTray.displayMessage(DavGatewayTray.java:96)
Thrown:

@untitaker
Copy link
Member

Could you try adding return x after this line in your installation?

@sboehringer
Copy link
Author

sboehringer commented Aug 26, 2016 •
edited

I did so and also inserted

    print ('orig  : %s' % orig_href)
    print ('native: %s' % href)

above the return x. The tail of the output ahead of the error message is given below. The to_native function does not appear to be unquoting the %3D (if i understand the meaning correctly). The error message stays exactly the same.

orig  : /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HKAAA%3D.EML
native: /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HKAAA%3D.EML
orig  : /users/S.Boehringer@lumc.nl/calendar/2c0c9e97-c0b6-40c7-bd29-ac19f2fb49b9.ics
native: /users/S.Boehringer@lumc.nl/calendar/2c0c9e97-c0b6-40c7-bd29-ac19f2fb49b9.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/3a64eec5-d0be-4562-82bc-259a7e982cf8.ics
native: /users/S.Boehringer@lumc.nl/calendar/3a64eec5-d0be-4562-82bc-259a7e982cf8.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/01badb29-3cd6-4568-b53c-c68b8ed427f0.ics
native: /users/S.Boehringer@lumc.nl/calendar/01badb29-3cd6-4568-b53c-c68b8ed427f0.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/023056df-d3e9-443f-baed-648e8ef41e41.ics
native: /users/S.Boehringer@lumc.nl/calendar/023056df-d3e9-443f-baed-648e8ef41e41.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/fbd6d708-9ce1-4ed6-8259-a41e1657f614.ics
native: /users/S.Boehringer@lumc.nl/calendar/fbd6d708-9ce1-4ed6-8259-a41e1657f614.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/af369be2-c2b6-4eb8-9472-6aee726c1080.ics
native: /users/S.Boehringer@lumc.nl/calendar/af369be2-c2b6-4eb8-9472-6aee726c1080.ics

@sboehringer
Copy link
Author

sboehringer commented Aug 26, 2016 •
edited

If I move the return x before the ...urlquote line, and print orig_href and x, I get:

orig  : /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HKAAA%3D.EML
proc  : /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HKAAA=.EML
orig  : /users/S.Boehringer@lumc.nl/calendar/2c0c9e97-c0b6-40c7-bd29-ac19f2fb49b9.ics
proc  : /users/S.Boehringer@lumc.nl/calendar/2c0c9e97-c0b6-40c7-bd29-ac19f2fb49b9.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/3a64eec5-d0be-4562-82bc-259a7e982cf8.ics
proc  : /users/S.Boehringer@lumc.nl/calendar/3a64eec5-d0be-4562-82bc-259a7e982cf8.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/023056df-d3e9-443f-baed-648e8ef41e41.ics
proc  : /users/S.Boehringer@lumc.nl/calendar/023056df-d3e9-443f-baed-648e8ef41e41.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/01badb29-3cd6-4568-b53c-c68b8ed427f0.ics
proc  : /users/S.Boehringer@lumc.nl/calendar/01badb29-3cd6-4568-b53c-c68b8ed427f0.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/fbd6d708-9ce1-4ed6-8259-a41e1657f614.ics
proc  : /users/S.Boehringer@lumc.nl/calendar/fbd6d708-9ce1-4ed6-8259-a41e1657f614.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/af369be2-c2b6-4eb8-9472-6aee726c1080.ics
proc  : /users/S.Boehringer@lumc.nl/calendar/af369be2-c2b6-4eb8-9472-6aee726c1080.ics
error: Unknown error occured for my_calendar/calendar: /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAABHFlNrAAA=.EML

@sboehringer
Copy link
Author

Finally, if not returning early, only printing orig_href and x, I get

orig  : /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HKAAA%3D.EML
proc  : /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HKAAA%3D.EML
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAAAkN0HKAAA%3D.EML'
orig  : /users/S.Boehringer@lumc.nl/calendar/2c0c9e97-c0b6-40c7-bd29-ac19f2fb49b9.ics
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/2c0c9e97-c0b6-40c7-bd29-ac19f2fb49b9.ics'
proc  : /users/S.Boehringer@lumc.nl/calendar/2c0c9e97-c0b6-40c7-bd29-ac19f2fb49b9.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/3a64eec5-d0be-4562-82bc-259a7e982cf8.ics
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/3a64eec5-d0be-4562-82bc-259a7e982cf8.ics'
proc  : /users/S.Boehringer@lumc.nl/calendar/3a64eec5-d0be-4562-82bc-259a7e982cf8.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/01badb29-3cd6-4568-b53c-c68b8ed427f0.ics
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/01badb29-3cd6-4568-b53c-c68b8ed427f0.ics'
proc  : /users/S.Boehringer@lumc.nl/calendar/01badb29-3cd6-4568-b53c-c68b8ed427f0.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/023056df-d3e9-443f-baed-648e8ef41e41.ics
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/023056df-d3e9-443f-baed-648e8ef41e41.ics'
proc  : /users/S.Boehringer@lumc.nl/calendar/023056df-d3e9-443f-baed-648e8ef41e41.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/fbd6d708-9ce1-4ed6-8259-a41e1657f614.ics
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/fbd6d708-9ce1-4ed6-8259-a41e1657f614.ics'
proc  : /users/S.Boehringer@lumc.nl/calendar/fbd6d708-9ce1-4ed6-8259-a41e1657f614.ics
orig  : /users/S.Boehringer@lumc.nl/calendar/af369be2-c2b6-4eb8-9472-6aee726c1080.ics
debug: Already normalized: '/users/S.Boehringer@lumc.nl/calendar/af369be2-c2b6-4eb8-9472-6aee726c1080.ics'
proc  : /users/S.Boehringer@lumc.nl/calendar/af369be2-c2b6-4eb8-9472-6aee726c1080.ics
error: Unknown error occured for my_calendar/calendar: /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAABHFlNrAAA%3D.EML
error: Use `-vdebug` to see the full traceback.
debug:   File "/usr/lib/python3.4/site-packages/vdirsyncer/cli/tasks.py", line 66, in sync_collection

@sboehringer
Copy link
Author

sboehringer commented Aug 26, 2016 •
edited

If I insert from urllib.parse import quote and replace

    x = utils.compat.urlquote(x, '/@%:')

with

    x = quote(x)

vdirsyncer gets utterly confused, spewing errors on every message, e.g.

debug: Normalized URL from '/users/S.Boehringer@lumc.nl/calendar/FBAA7915-ADE9-453D-8915-508EA3C05F17%253B1241204GRAVEIN%2540kpnconferencing.nl.ics' to '/users/S.Boehringer%40lumc.nl/calendar/FBAA7915-ADE9-453D-8915-508EA3C05F17%253B1241204GRAVEIN%2540kpnconferencing.nl.ics'
warning: Skipping '/users/S.Boehringer%40lumc.nl/calendar/FBAA7915-ADE9-453D-8915-508EA3C05F17%253B1241204GRAVEIN%2540kpnconferencing.nl.ics', properties are missing.
orig  : /users/S.Boehringer@lumc.nl/calendar/FBAA7915-ADE9-453D-8915-508EA3C05F17%253B1240697GRAVEIN%2540kpnconferencing.nl.ics
debug: Unsafe character: '%3B'
proc  : /users/S.Boehringer%40lumc.nl/calendar/FBAA7915-ADE9-453D-8915-508EA3C05F17%253B1240697GRAVEIN%2540kpnconferencing.nl.ics

@sboehringer
Copy link
Author

I believe that the problem is not due to mis-quoting. I got confused by the partial quoting of the URL but this seems to be handled well somehow, as the DavMail requests never results in an error. Also vdirsyncer fetches a lot of events and only bails out later in the processing.

According to DavMail the request looks as follows:

Date:           Fri Aug 26 12:30:29 CEST 2016 (1472207429202)
Thread:     CaldavConnection-59741
Message #:  1796
Level:      DEBUG
NDC:            
Category:   davmail.exchange.ExchangeSession
Message:        Get event: AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAABHFlNRAAA=.EML
Location:   davmail.exchange.ews.EwsExchangeSession$Event.getEventContent(EwsExchangeSession.java:1751)
Thrown:

The response looks like:

Date:           Fri Aug 26 12:27:15 CEST 2016 (1472207235045)
Thread:     CaldavConnection-59734
Message #:  1797
Level:      DEBUG
NDC:            
Category:   davmail.exchange.ExchangeSession
Message:        Vcalendar body received from server:
BEGIN:VCALENDAR
METHOD:PUBLISH
PRODID:Microsoft Exchange Server 2010
VERSION:2.0
BEGIN:VTIMEZONE
TZID:Europe/Berlin
BEGIN:STANDARD
DTSTART:16010101T030000
TZOFFSETFROM:+0200
TZOFFSETTO:+0100
RRULE:FREQ=YEARLY;INTERVAL=1;BYDAY=-1SU;BYMONTH=10
END:STANDARD
BEGIN:DAYLIGHT
DTSTART:16010101T020000
TZOFFSETFROM:+0100
TZOFFSETTO:+0200
RRULE:FREQ=YEARLY;INTERVAL=1;BYDAY=-1SU;BYMONTH=3
END:DAYLIGHT
END:VTIMEZONE
BEGIN:VEVENT
ORGANIZER;CN="Invitor (MSTAT)":MAILTO:invitor@lumc.nl
DESCRIPTION;LANGUAGE=en-US:Quando: giovedì 19 novembre 2015 10.30-11.30. ((UT
 C + 1.00 h) Amsterdam, Berlino, Berna, Roma, Stoccolma, Vienna\n\n*~*~*~*~*~
 *~*~*~*~*\n\n\n
SUMMARY;LANGUAGE=en-US:Appointment
DTSTART;TZID="Europe/Berlin":20151119T103000
DTEND;TZID="Europe/Berlin":20151119T113000
UID:040000008200E00074C5B7101A82E008000000005F4919155720D10100000000000000001
 00000008694FDD7E71B5C4D8394438C8680AD4E
CLASS:PUBLIC
PRIORITY:5
DTSTAMP:20151119T092613Z
TRANSP:OPAQUE
STATUS:CONFIRMED
SEQUENCE:0
X-MICROSOFT-CDO-APPT-SEQUENCE:0
X-MICROSOFT-CDO-OWNERAPPTID:2113635935
X-MICROSOFT-CDO-BUSYSTATUS:BUSY
X-MICROSOFT-CDO-INTENDEDSTATUS:BUSY
X-MICROSOFT-CDO-ALLDAYEVENT:FALSE
X-MICROSOFT-CDO-IMPORTANCE:1
X-MICROSOFT-CDO-INSTTYPE:0
X-MICROSOFT-DISALLOW-COUNTER:FALSE
ATTENDEE;CN="Böhringer, S. (MSTAT)";PARTSTAT=ACCEPTED;ROLE=REQ-PARTICIPANT:ma
 ilto:S.Boehringer@lumc.nl
LAST-MODIFIED:20151120T122240Z
X-MOZ-LASTACK:20151119T092613Z
END:VEVENT
END:VCALENDAR

I noticed, that in the request the string contains an NR instead of Nr as in the url

error: Unknown error occured for my_calendar/calendar: /users/S.Boehringer@lumc.nl/calendar/AAMkADFhMDg1YzYwLTgwMDItNDJiYi1hNmY2LTgxZDI1MDcwNmIzMgBGAAAAAAAutjjQvZGzQZDR7unScTwfBwA4R1qAXwlGQ7K94p6FsS4bAAAA66iHAAD2R2asQXn-SImONQz5BBbsAABHFlNrAAA%3D.EML

@sboehringer
Copy link
Author

After deleting the offending event, vdirsync bombed out on another one. After deleting that event as well, syncing worked.
Maybe syncing could be made robust to such events? Catching an error around the event insertion and ignoring the problem instead of exiting?

@untitaker
Copy link
Member

To do this cleanly it requires a lot of changes in vdirsyncer. Also I worry about skipping few events (such that user doesn't notice and misses e.g. a meeting) a lot.

@untitaker untitaker mentioned this issue Sep 8, 2016
Closed
@jvasile jvasile mentioned this issue Apr 14, 2021
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
cat: server compat mod: DAV type: bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@untitaker @sboehringer