No events being shown: "invalid date-time value"

[karloluiten]

Steps to reproduce

1. Open my calendar ('Personal')
2. Wait for events to load
3. Spinner keeps spinnging, errors show in the console

Expected behaviour

Events should show up in my calendar ;)

Actual behaviour

UI loads, my 'contacts birthday' calendar loads fine, my 'Personal' calendar does not work. It DOES work on my android phone though(!), through CalDAV over DavDROID.
"Does not work" means the spinner keeps spinning and javascript log shows errors.

Server configuration

Operating system: Centos7 with EPEL and all patches applied

Web server: httpd-2.4.6-45.el7.centos.x86_64

Database: sqlite3

PHP version: PHP Version 7.0.16

Server version: Nextcloud 11.0.2 (production)

Calendar version: Calendar 1.5.2

Updated from an older installed version or fresh install: Updated from older

Signing status (ownCloud/Nextcloud 9.0 and above):

Integrity checker has been disabled. Integrity cannot be verified.

List of activated apps:

Enabled:
  - activity: 2.4.1
  - admin_audit: 1.1.0
  - announcementcenter: 3.0.0
  - bookmarks: 0.9.1
  - calendar: 1.5.2
  - comments: 1.1.0
  - contacts: 1.5.3
  - dav: 1.1.1
  - direct_menu: 0.10.0
  - federatedfilesharing: 1.1.1
  - federation: 1.1.1
  - files: 1.6.1
  - files_automatedtagging: 1.1.1
  - files_markdown: 1.0.1
  - files_pdfviewer: 1.0.1
  - files_retention: 1.0.1
  - files_sharing: 1.1.1
  - files_texteditor: 2.2
  - files_trashbin: 1.1.0
  - files_versions: 1.4.0
  - files_videoplayer: 1.0.0
  - firstrunwizard: 2.0
  - gallery: 16.0.0
  - logreader: 2.0.0
  - lookup_server_connector: 1.0.0
  - news: 10.1.0
  - nextcloud_announcements: 1.0
  - notes: 2.2.0
  - notifications: 1.0.1
  - password_policy: 1.1.0
  - provisioning_api: 1.1.0
  - serverinfo: 1.1.1
  - sharebymail: 1.0.1
  - spreed: 1.2.0
  - survey_client: 0.1.5
  - systemtags: 1.1.3
  - templateeditor: 0.2
  - theming: 1.1.1
  - twofactor_backupcodes: 1.0.0
  - updatenotification: 1.1.1
  - workflowengine: 1.1.1
Disabled:
  - apporder
  - encryption
  - external
  - files_accesscontrol
  - files_external
  - tasks
  - user_external
  - user_ldap
  - user_saml

The content of config/config.php:

{
    "system": {
        "instanceid": "oc2ck5u2i8v0",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "***REMOVED SENSITIVE VALUE***.nl",
            "nc.***REMOVED SENSITIVE VALUE***.nl"
        ],
        "datadirectory": "\/var\/www\/html\/nextcloud\/data",
        "overwrite.cli.url": "https:\/\/***REMOVED SENSITIVE VALUE***.nl\/nextcloud",
        "dbtype": "sqlite3",
        "version": "11.0.2.7",
        "logtimezone": "UTC",
        "installed": true,
        "theme": "",
        "loglevel": 0,
        "maintenance": false,
        "trashbin_retention_obligation": "30",
        "mail_from_address": "nextcloud",
        "mail_smtpmode": "php",
        "mail_domain": "***REMOVED SENSITIVE VALUE***.nl",
        "updater.release.channel": "production"
    }
}

Are you using external storage, if yes which one: no

Are you using encryption: no

Are you using an external user-backend, if yes which one: no

Client configuration

Browser: FireFox 52.0

Operating system: Fedora 25

CalDAV-clients: Browser (not working), android (working), thunderbird (working)

Logs

Web server error log

***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:50 +0100] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 200 74 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:56 +0100] "GET /index.php/apps/calendar/ HTTP/1.1" 200 72076 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:57 +0100] "PROPFIND /remote.php/dav HTTP/1.1" 207 583 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:58 +0100] "POST /index.php/apps/calendar/v1/config HTTP/1.1" 200 2 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:58 +0100] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 200 74 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:58 +0100] "PROPFIND /remote.php/dav/principals/users/user/ HTTP/1.1" 207 591 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:58 +0100] "GET /index.php/apps/calendar/v1/timezones/EUROPE/BERLIN.ics HTTP/1.1" 200 356 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:58 +0100] "PROPFIND /remote.php/dav/calendars/user/ HTTP/1.1" 207 9628 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:58 +0100] "REPORT /remote.php/dav/calendars/user/contact_birthdays/ HTTP/1.1" 207 283 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:26:58 +0100] "REPORT /remote.php/dav/calendars/user/personal/ HTTP/1.1" 207 138429 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"
***REMOVED SENSITIVE VALUE***- - [22/Mar/2017:07:27:03 +0100] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 200 74 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:52.0) Gecko/20100101 Firefox/52.0"

Error log does not hold a lot of entries:

Log file (data/owncloud.log)

{"reqId":"WGVyCHrkshAHj-wy7wdjNgAAAAc","remoteAddr":"***REMOVED SENSITIVE VALUE***","app":"PHP","message":"Class 'Google_Service' not found at \/usr\/share\/php\/Google\/Service\/Drive.php#32","level":3,"time":"2016-12-29T20:28:56+00:00","method":"GET","url":"\/nextcloud\/index.php\/settings\/admin","user":"admin"}
{"reqId":"WGVynnfqZ@9oq0bgprU9EwAAAAY","remoteAddr":"***REMOVED SENSITIVE VALUE***","app":"PHP","message":"Class 'Google_Service' not found at \/usr\/share\/php\/Google\/Service\/Drive.php#32","level":3,"time":"2016-12-29T20:31:27+00:00","method":"GET","url":"\/nextcloud\/index.php\/settings\/admin","user":"admin"}
{"reqId":"WGVzdgp2BY8IVY48bj7USAAAAAA","remoteAddr":"***REMOVED SENSITIVE VALUE***","app":"PHP","message":"Class 'Google_Service' not found at \/usr\/share\/php\/Google\/Service\/Drive.php#32","level":3,"time":"2016-12-29T20:35:02+00:00","method":"GET","url":"\/nextcloud\/index.php\/settings\/admin","user":"admin"}
{"reqId":"WGVz28JcpjuHY7uEbh7cagAAAAo","remoteAddr":"***REMOVED SENSITIVE VALUE***","app":"PHP","message":"Class 'Google_Service' not found at \/usr\/share\/php\/Google\/Service\/Drive.php#32","level":3,"time":"2016-12-29T20:36:43+00:00","method":"GET","url":"\/nextcloud\/index.php\/settings\/admin","user":"admin"}

(=not recent)

Browser log

Error: invalid date-time value: "2017-03-03T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-07T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-17T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-05T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-12T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-08T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-19T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-02-27T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-14T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-01T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-15T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-11T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-27T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-17T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-09T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-05T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-06T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-26T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-05T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-07T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-09T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-06T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-04T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-15T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-18T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-22T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-11T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-03T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-01T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-06T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-06T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-03T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-22T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-16T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-02T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-05T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-14T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-09T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-27T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-05T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-15T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-22T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-03-06T::"  vendor.min.js:20:14510
Error: invalid date-time value: "2017-04-05T::"  vendor.min.js:20:14510

Suspicion

I think some event dates are broken and I want to blame my imported facebook birthdays, but I have no evidence of that.

[georgehrke]

I see two bugs here:

• the calendar itself should load fine even if some events are broken
• the fb birthday fix doesn't kick in (https://github.com/nextcloud/calendar/blob/master/js/app/models/veventModel.js#L327)

[karloluiten]

Thanks for taking a look at this/tagging and commenting.

Is there anything I can do? Or do you have enough data? Thanks a lot.

[georgehrke]

I think I have enough data to fix this.
I'll look into this in the next couple of days and will get back to you when I need more information :)

[karloluiten]

Is there news? Let me know if I can help :)

[georgehrke]

Can you provide me sample ics please.
FB actually fixed their birthday calendar, so i can't use that.

[karloluiten]

What I did:
Get random error from console:

"Error: invalid date-time value: "2017-05-02T::"

Get response from REPORT request to https://nc.***.nl/remote.php/dav/calendars/***/personal/

Looked for the string "2017-05-02T::". No results (?). Then I looked for 20170502 and got 3 matching VEVENTS:

BEGIN:VEVENT
DTSTART:20170502
SUMMARY::***'s birthday
RRULE:FREQ=YEARLY
DURATION:P1D
UID:b100001558480645@facebook.com
END:VEVENT
BEGIN:VEVENT
DTSTART:20170502
SUMMARY::***'s birthday
RRULE:FREQ=YEARLY
DURATION:P1D
UID:b100002718611916@facebook.com
END:VEVENT
BEGIN:VEVENT
DTSTART:20170502
SUMMARY:***'s birthday
RRULE:FREQ=YEARLY
DURATION:P1D
UID:b100000416765820@facebook.com
END:VEVENT

Is this what you were looking for?

[georgehrke]

Did you disable all other calendars and only try to load the broken one?

Looked for the string "2017-05-02T::". No results (?). Then I looked for 20170502 and got 3 matching VEVENTS:

😕

Can you please double check?
2017-05-02T:: has to come from somewhere.

Searching for T:: should be enough.

[karloluiten]

• Created a test calendar, shows fine and I can add calendars
• Disabled the test and "Contact birthdays" calendar
• Reload, see the same error (it still seems to load the Contact birthdays" calendar, odd)
• I get the "Response" tab from the REPORT request. ''No T:: in there'', which I find very odd.
• I downloaded the 'personal' calendar (the broken one), searched the ics file, ''Also no T:: in there".
• To be sure I also downloaded the other 2 calendars, no T:: there either.
• I got the whole error list and kept my phone (which has a working calendar) next to it: it matches 1:1 to facebook birthdays on my calendar. Example:

BEGIN:VEVENT
DTSTART:20170502
SUMMARY:***'s birthday
RRULE:FREQ=YEARLY
DURATION:P1D
UID:b100000416765***@facebook.com
END:VEVENT

Are the events maybe being rewritten somewhere? I can't really explain it otherwise. Thanks a lot for your time though!

[georgehrke]

DTSTART:20170502

Ah, obviously 🙈
It's supposed to be DTSTART;VALUE=DATE:20170502, we can catch that error.

[karloluiten]

I see this code:

293       if (findTypes.indexOf(dateType) >= 0 && el.trim().substr(-3) === 'T::') { // is date without time
294         icsDate = el.replace(/[^0-9]/g, '');
295         ics = ics.replace(el, dateType + ';VALUE=DATE:' + icsDate);
296       }

That will not match the time-less thing I suppose :).

-edit- just see your post, think we got something :)