387559 - Event creation/change fails if server requires authentication for write (PUT) but not for read (GET)

Status: RESOLVED FIXED

(Calendar :: Provider: ICS/WebDAV, defect)

Description

[Stefan Sitter [:ssitter]]

Creating event on webdav server using https url fails

Steps to Reproduce:
===================
1. Create new Sunbird profile
2. Subscribe to https://mozilla.kewis.ch/dav/ssitter.ics
3. Accept the certificate for mozilla.kewis.ch permanently
4. Finish the New Calendar Wizard
5. Create new event -> authentication dialog is shown
6. Enter user name and password for https://mozilla.kewis.ch

Actual Results:
===============

No event is created. Console shows error (see below). After switching view no events are displayed anymore. Sunbird process hangs during shutdown and must be killed.

Expected Results:
=================

Event is created and is visible in view.

Additional Information:
=======================

Same steps work fine using http://mozilla.kewis.ch/dav/ssitter.ics instead.

Regression Range:
=================

WORKS in sunbird-0.4a1.en-US.win32-2007-01-10-08-trunk

FAILS in sunbird-0.4a1.en-US.win32-2007-01-10-14-trunk

Error: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.requestSucceeded]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: file:///Y:/sunbird-0.4a1.en-US.win32-2007-01-10-14-trunk/components/calICSCalendar.js :: anonymous :: line 361"  data: no]

FAILS in sunbird-0.7pre.en-US.win32-2007-07-10-06-mozilla1.8

Error: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.requestSucceeded]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: file:///Y:/sunbird-0.7pre.en-US.win32-2007-07-10-06-mozilla1.8/components/calICSCalendar.js :: anonymous :: line 383"  data: no]

Comment 1

[Philipp Kewisch [:Fallen] [:📆][:🧩]]

The configuration of http and https differed. http required a login for ALL operations, while https had the following limitation for operations that require a login.

<Limit PUT POST DELETE PROPFIND PROPPATCH MKCOL COPY MOVE LOCK UNLOCK>

Either the webdav implementation doesn't like only certain methods being restricted, or I restricted the wrong set of methods.

Comment 2

[Stefan Sitter [:ssitter]]

(In reply to comment #1)

OK, so the error seen here goes back to the servers Limit/LimitExcept, as noted in the release notes. Now that the rule is removed from the server event creation also works using the https url.

At least we now have a regression range. The only calendar checkin during that time was for Bug 364841. 

Michiel, could you elaborate how Bug 364841 changed the network behavior of the ics provider?

Comment 3

[Stefan Sitter [:ssitter]]

During QA chat we decided to use this bug to track this issue. 
Changing summary to "Event creation/change fails if server requires authentication for write (PUT) but not for read (GET)".

Comment 6

[Chuck Meyer]

Hi, reposting my details form case 379498 since it was marked as duplicate.  Hope this helps:

I have modified my httpd.conf as recommended in the release notes (added
PROPFIND to the LimitExcept list).  Now I now longer have my calendar events
disappear after a modify, however I still get the error.  Here's is my current
settings for my /dav directory:

DAVLockDB /Library/WebServer/davlocks/DAVLockDB
DAVMinTimeout 600

<Location /dav/>
    DAV On
    AuthType Basic
    AuthName "WebDAV Restricted"
    AuthUserFile "/etc/httpd/passwords/webdav.access"
    <LimitExcept GET HEAD OPTIONS PROPFIND>
        Require user webdav
    </LimitExcept>
</Location>

The calendar I created was as follows:
New... --> On the Network --> iCalendar(ICS) --> Location:
http://www.secretlair.net:8888/dav/Events.ics --> Name: Events

Error text is the same as above. Access logs still show 401 return code on a
PUT, then nothing.

I added PUT to the LimitExcept list and it worked like a charm

Comment 7

[Ed]

Per the discussion in 380291 and 380292, this issue can lead to a non-terminating Sunbird process on Windows.

380292 contains apache server logs showing that the web server never sees a PUT with the password (even though Sunbird did prompt me for that password).

Comment 8

[Michiel van Leeuwen (email: mvl+moz@)]

(In reply to comment #2)
> Michiel, could you elaborate how Bug 364841 changed the network behavior of the
> ics provider?

The only thing I can think of is that the notification callbacks are only set on the channel, not on the upload channel. (in calICSCalendar.js, around line 319). But i'd say that both are actually the same. But it would be worth testing that. Problem is that I don't have an easy way to test that idea. Any volunteers?

Comment 9

[Chuck Meyer]

(In reply to comment #7)
> Per the discussion in 380291 and 380292, this issue can lead to a
> non-terminating Sunbird process on Windows.
> 
> 380292 contains apache server logs showing that the web server never sees a PUT
> with the password (even though Sunbird did prompt me for that password).
> 

I'd like to confirm end result is similar in Lightning -- end result is a non-terminating Thunderbird process.

Comment 10

[Chuck Meyer]

I'd volunteer but I don't know what needs to be done?  Are you proposing a modification to the .js file?

Regards?

(In reply to comment #8)
> (In reply to comment #2)
> > Michiel, could you elaborate how Bug 364841 changed the network behavior of the
> > ics provider?
> 
> The only thing I can think of is that the notification callbacks are only set
> on the channel, not on the upload channel. (in calICSCalendar.js, around line
> 319). But i'd say that both are actually the same. But it would be worth
> testing that. Problem is that I don't have an easy way to test that idea. Any
> volunteers?
> 

Comment 14

[Sebastian Schwieger]

(In reply to comment #8)
> The only thing I can think of is that the notification callbacks are only set
> on the channel, not on the upload channel. (in calICSCalendar.js, around line
> 319). But i'd say that both are actually the same. But it would be worth
> testing that. Problem is that I don't have an easy way to test that idea. Any
> volunteers?
> 
I changed 
channel.notificationCallbacks = savedthis;
to
uploadChannel.notificationCallbacks = savedthis;
but that didn't change anything.

Comment 15

[Sebastian Schwieger]

Attachment: move if block into try block

After a lot of testing I found that moving the first if block into the above try block in onStopRequest() does the trick. Furthermore, I removed one argument from onStopRequest(), since it should have three arguments according to xulplanet. Please correct me if I'm wrong.

Comment 16

[Michiel van Leeuwen (email: mvl+moz@)]

Why does this patch makes thing work?
My guess is that it hides the error, by wrapping it in a try block. That doesn't leave me with a very comfortable feeling.

The patch removes an 'else if', and turns it into an 'if'. But that else was there for a reason. It should catch error in for example ftp, that are not caught in the block above. Without the else, i think that it will catch http errors twice.

I think the cause of the error is actually documented at http://lxr.mozilla.org/seamonkey/source/netwerk/protocol/http/public/nsIHttpChannel.idl#213


213      * @throws NS_ERROR_NOT_AVAILABLE if called before the response
214      *         has been received (before onStartRequest).

So a solution might be to check if onStartRequest has been called before. If not, we should not query for the channel.requestSucceeded.

Comment 17

[Sebastian Schwieger]

(In reply to comment #16)
> The patch removes an 'else if', and turns it into an 'if'. But that else was
> there for a reason. It should catch error in for example ftp, that are not
> caught in the block above. Without the else, i think that it will catch http
> errors twice.
I thought that the if and the else if are totally exclusive:
 if (channel...
versus
 else if (!channel...
Thats why I felt save in turning else if into if. Am I wrong here?
> 
> I think the cause of the error is actually documented at
> http://lxr.mozilla.org/seamonkey/source/netwerk/protocol/http/public/nsIHttpChannel.idl#213
> 
> 
> 213      * @throws NS_ERROR_NOT_AVAILABLE if called before the response
> 214      *         has been received (before onStartRequest).
> 
> So a solution might be to check if onStartRequest has been called before. If
> not, we should not query for the channel.requestSucceeded.
> 
That sounds reasonable. I am not sure however, if we gain anything by checking for it. I could also imagine to only wrap the call to requestSucceeded into a try block and leave the rest as it is.

Comment 18

[Sebastian Schwieger]

I just tried an implementation where I checked if onStartRequest has been called. But still the error is thrown. So there might be other reasons why channel.requestSucceded throws.

Comment 19

[Daniel Boelzle [:dbo]]

Comment on attachment 276264 [details] [diff] [review]
move if block into try block

Moving over to mvl since he has already commented on the patch. Thanks for helping out, mvl!

Comment 20

[Fons Rademakers]

I'am having the exact same problems on Mac OS X with the 0.5 version and an identical Apache 2.0 webdav setup. I notice that after applying the proposed patch the following happens:

start sunbird 0.5
add an event
exit

the event is not added (in the access.log I see a 401 PUT error), but total silence from sunbird about the 401 error, so the user looses silently the event.

However if I do:

start sunbird 0.5
add an event
move the event to another day
move the event back
exit

the event is added (still first a silent 401 PUT, but then a successful 204 PUT !)

Idem for deleting events, move an event then delete it. Also once the PUT succeeded, it keeps succeeding. So at startup move an event and the thing seems to work for the entire session.
Hardly rock-solid and confidence building. Kind of amazing that this showstopper takes this long to solve.

Cheers, Fons.

Comment 21

[Sebastian Schwieger]

Comment on attachment 276264 [details] [diff] [review]
move if block into try block

Testing this on another box I see that the patch does not fix the bug. I will figure out the different setups by tomorrow. Removing review request.

Comment 22

[Sebastian Schwieger]

Attachment: check for onStartRequest

Confirming comment 20. The first PUT gets a 401 response and a Auth dialog pops up. However, a second PUT is not attempted after pressing OK.

My comment 18 was wrong. Indeed, onStartRequest() is not called on the first PUT attempt (response: 401). Checking for that is possible.

To solve comment 20, I added a doWriteICS() call in case onStartRequest has not been called. This is probably a naive way of fixing this. Waiting for comments.

Comment 23

[Fons Rademakers]

Hi Sebastian,

  after applying the patch to my Sunbird 0.5 on Mac OS X things look to work properly. Very nice.

Cheers, Fons.

Comment 24

[Stefan Sitter [:ssitter]]

Comment on attachment 277242 [details] [diff] [review]
check for onStartRequest

I tested the patch with the STR from Comment #0 and it works fine now.

Comment 25

[Michiel van Leeuwen (email: mvl+moz@)]

Has this fixed itself? I can't reproduce with either my own branch build or a build from ftp. I'm using the STR from comment 0, and tried to copy the apache setup from comment 6. I always get a nice prompt asking me for a username and password.

Comment 26

[Stefan Sitter [:ssitter]]

(In reply to comment #25)
The error happens after entering username/password and closing the prompt with OK in the STR from comment 0.

Comment 27

[Michiel van Leeuwen (email: mvl+moz@)]

I can reproduce this now, thanks for the additional info.

After looking into this a bit more, it seems to me that we are hit by some necko problem. nsIRequestObserver states:
 63      * Called to signify the end of an asynchronous request.  This
 64      * call is always preceded by a call to onStartRequest.
(http://lxr.mozilla.org/seamonkey/source/netwerk/base/public/nsIRequestObserver.idl#62)

But somehow, our call is not preceded by onStartRequest. That looks like a necko bug, triggered by our use of streams. Somehow, re-creating a stream with auth info on the upload channel fails, because the input stream is closed.

I'll attach logs later, just wanted to let you know why the review is not yet there. I'm still thinking about whether we should try to fix the real bug or use a workaround like the proposed patch.

Comment 28

[Michiel van Leeuwen (email: mvl+moz@)]

Attachment: proof of concept

I played around a bit more, and this patch shows that there is something with our stream handling. The patch makes uploading work for me.
I'm not sure what it does with character encoding etc, because that part of the serializer is simply skipped. The patch is also not really clean, so not requesting any review yet.

Comment 29

[Christian :Biesinger (don't email me, ping me on IRC)]

if you get onStopRequest without onStartRequest, that's a serious necko bug; you should file it with a testcase. however, bug 388523 fixed one such case, maybe that's what you were seeing there?

Comment 30

[Michiel van Leeuwen (email: mvl+moz@)]

Attachment: log of failed upload

This is a log made of an attempt to upload (to my localhost) without any patches applied, thus the upload fails. The start of the log is download of the file before editing, so start reading at the end.

Comment 31

[Michiel van Leeuwen (email: mvl+moz@)]

(In reply to comment #29)
> however, bug 388523 fixed one such case, maybe that's what you were seeing there?

I've alreay tried to apply that patch to the 1.8 branch (which i'm using), and still could not upload. onStartRequest did get called, but did not receive any headers. Trying to access the status code etc thus still failed.

Comment 32

[Stefan Sitter [:ssitter]]

Using my own Sunbird mozilla1.8 branch debug build I see no assertion but the following warning before the JavaScript error if I enter the correct username and password:

  WARNING: NS_ENSURE_TRUE(NS_SUCCEEDED(rv)) failed, 
  file y:/dev/mozilla/xpcom/io/nsMultiplexInputStream.cpp, line 177


If I cancel the password prompt I get the following error before the message dialog "Status code: 401: Authorization Required" is displayed:

  ###!!! ASSERTION: OnDataAvailable implementation consumed no data: 'Error', 
  file y:/dev/mozilla/netwerk/base/src/nsInputStreamPump.cpp, line 516

and the useless message in Console:

  Error: Assert failed: Bad log argument.
  1: ASSERT
  2: LOG
  3: 
  Source File: file:///Y:/obj/dist/bin/js/calUtils.js   Line: 647

Comment 33

[Sebastian Schwieger]

Comment on attachment 277242 [details] [diff] [review]
check for onStartRequest

mvl, thanks for taking care of the real fix.

Comment 34

[Michiel van Leeuwen (email: mvl+moz@)]

This is not 'the' real fix.
As I see it, there are a couple of related problems:
- failure in DoAuthRetry causes OnStartRequest to be not calleb, but only OnStopRequest. That's a problem, but not what causes this bug
- Somehow, nsIPipe doesn't work with DoAuthRetry. Should that be fixed or worked around? I don't really know how to properly fix it. Maybe the problem is in the sting stream that's being used, and not so much in the pipe. I just don't know.
- My patch is a workaround for nsIPipe. Problem with my patch is that all the charset encoding issues need to be carefully figured out, and tested a lot. So there is work to do there too.

Comment 35

[Martin Schröder [:mschroeder]]

Daniel, this is definitely a blocker (decision on the QA chat).

Comment 36

[Daniel Boelzle [:dbo]]

I agree; I had a short chat with mvl yesterday and hoped he's going to take that bug since he wanted it to be 0.7+.

Comment 37

[Christian :Biesinger (don't email me, ping me on IRC)]

Ah, I see where the problem is. You shouldn't use a pipe as an upload channel's stream. nsIUploadChannel.idl says:

 57      * Most implementations of this interface require that the stream:
[...]
 60      *   (3) implement nsISeekableStream::seek

And pipe input streams don't do that; they discard the data once read.

You should probably use a storage stream instead.

Comment 38

[Christian :Biesinger (don't email me, ping me on IRC)]

(or a string stream, if that works better for you)

Comment 39

[Christian :Biesinger (don't email me, ping me on IRC)]

(In reply to comment #32)
>   ###!!! ASSERTION: OnDataAvailable implementation consumed no data: 'Error', 
>   file y:/dev/mozilla/netwerk/base/src/nsInputStreamPump.cpp, line 516

As for that assertion, your implementation of onDataAvailable in calICSCalendar.js is incorrect, you need to read all available data from the input stream...

Comment 40

[Daniel Boelzle [:dbo]]

(In reply to comment #39)
> As for that assertion, your implementation of onDataAvailable in
> calICSCalendar.js is incorrect, you need to read all available data from the
> input stream...
We are reading UTF-8, and need to convert those fragments right away to store them at the listener. Could we do that reliably in js code using the scriptable input stream? Does it work for incomplete UTF-8 sequences which may occur? How urging is that exception?

As an alternative, I'd like to throw in my proposal about using the unichar-stream-loader again, but as mvl correctly pointed out: it replaces invalid UTF-8 sequences, so on roundtripping, this may cause dataloss, strictly spoken. IMO we have to make our minds up to what extend we allow relaxed reading / data repair. One could also argue that repairing UTF-8 data is actually an improvement since it's been invalid before.

Comment 41

[Daniel Boelzle [:dbo]]

Attachment: missing unlocks

Potentially unsafe code => leads to locked queue.

Comment 42

[Philipp Kewisch [:Fallen] [:📆][:🧩]]

I have tried to use the unichar-stream-loader in the gdata provider at some point, but that failed in some cases. I think especially when there was no body it threw at a totally different point in time which lead to much code duplication. Maybe you can find a better way to use it though.

Comment 43

[Daniel Boelzle [:dbo]]

(In reply to comment #42)
Hmm, I have not encountered any problems using it in WCAP.

Comment 44

[Michiel van Leeuwen (email: mvl+moz@)]

(In reply to comment #40)
> We are reading UTF-8, and need to convert those fragments right away to store
> them at the listener.

This bug is about uploading, so the data that might be returned can be ignored (it will usually be some html describing that you need to log in). So using unichar-stream-loader is not relevant here.

Comment 45

[Michiel van Leeuwen (email: mvl+moz@)]

Comment on attachment 280120 [details] [diff] [review]
missing unlocks

I don't know what this patch has to do with the bug here, but i'll look into it. But please, post followup patches in a new bug, to not clutter this one.

>Index: calICSCalendar.js
>+        try {
>+            if (!this.mUri)
>+                throw Components.results.NS_ERROR_FAILURE;
>+            // makeBackup will call doWriteICS
>+            this.makeBackup(this.doWriteICS);
>+        } catch (exc) {
>+            this.unlock();
>+        }

You much the exception you just threw. A bit useless, if you ask me. So re-throw the exception, please. Or use finally (if that also works when you don't use catch. I'm not sure of that)

r- based on hiding errors.

Comment 46

[Michiel van Leeuwen (email: mvl+moz@)]

Attachment: cleaned patch

This patch is a cleaned version of the proof-of-concept patch. I noticed that serializeToStream wasn't used anywhere else, so I could change it to return an nsIInputStream. The stream that the ics service creates can be passed back directly, because it is utf-8 already (see http://lxr.mozilla.org/seamonkey/source/calendar/base/public/calIICSService.idl#130)

I can't test if the patch really fixes the bug, because I don't have access to a properly configured http server at the moment. But I did test the proof of concept patch, and it worked there. And this patch does the same, so it should still work.

Comment 47

[Daniel Boelzle [:dbo]]

Comment on attachment 280120 [details] [diff] [review]
missing unlocks

Moved review to bug 393387 which fits better.

Comment 48

[Michiel van Leeuwen (email: mvl+moz@)]

Attachment: updated patch

The previous patch ignored the ics exported. That exported does in fact need an outputstream (because writing to a local file needs that), so i added a method to create an inputstream, ans left the original code as it is.

Comment 49

[Daniel Boelzle [:dbo]]

Comment on attachment 280165 [details] [diff] [review]
updated patch

one minor nit:
>+calIcsSerializer.prototype.serializeToInputStream =
...
>+    return;
>+};
remove that return statement.

works well and fixes the bug; r=dbo

Comment 50

[Daniel Boelzle [:dbo]]

If channel.requestSucceeded is 0, function LOG asserts its message arg:
  ASSERT(aArg, "Bad log argument.", false);

Could you please also fix that false positive ASSERTs when checking in?
  LOG(channel.requestSucceeded);
maybe to 
  LOG("calIcsCalendar channel.requestSucceeded: " + channel.requestSucceeded);

Comment 51

[Simon Paquet [:sipaq]]

Daniel, is this bug really already fixed? I don't see a corresponding checkin.

Comment 52

[Daniel Boelzle [:dbo]]

damn, however I did that, I messed it up! sorry.

Comment 53

[Michiel van Leeuwen (email: mvl+moz@)]

patch checked in

Comment 54

[Christian :Biesinger (don't email me, ping me on IRC)]

+         scriptableInputStream.read(-1);

you're supposed to only read count bytes

Though, if you don't care about the data, what you could also do is throw an exception (any one will work).

Comment 55

[Kelv]

Patch in nightly from 12th Sept 5.29pm works here. Using LimitExcept GET HEAD OPTIONS PROPFIND.

PUT /calendar/testcal.ics HTTP/1.1" 401 401
PUT /calendar/testcal.ics HTTP/1.1" 204
PROPFIND /calendar/testcal.ics HTTP/1.1" 207 360

Excellent!