Closed Bug 387559 Opened 13 years ago Closed 12 years ago

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

Categories

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

defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: ssitter, Assigned: mvl)

References

Details

(Keywords: regression, Whiteboard: [0.5 publish fails])

Attachments

(2 files, 5 obsolete files)

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]
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.
(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?
Whiteboard: [0.5 publish fails]
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)".
Summary: Creating event on webdav server using https url fails → Event creation/change fails if server requires authentication for write (PUT) but not for read (GET)
Keywords: regression
OS: Windows 2000 → All
Hardware: PC → All
Duplicate of this bug: 380746
Duplicate of this bug: 379498
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
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).
(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?
(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.
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?
> 

Duplicate of this bug: 390084
Duplicate of this bug: 380291
Duplicate of this bug: 391383
(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.
Attached patch move if block into try block (obsolete) — Splinter Review
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.
Assignee: nobody → sebo.moz
Status: NEW → ASSIGNED
Attachment #276264 - Flags: review?(daniel.boelzle)
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.
(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.
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 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!
Attachment #276264 - Flags: review?(daniel.boelzle) → review?(mvl)
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 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.
Attachment #276264 - Flags: review?(mvl)
Attached patch check for onStartRequest (obsolete) — Splinter Review
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.
Attachment #276264 - Attachment is obsolete: true
Attachment #277242 - Flags: review?
Attachment #277242 - Flags: review? → review?(mvl)
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 on attachment 277242 [details] [diff] [review]
check for onStartRequest

I tested the patch with the STR from Comment #0 and it works fine now.
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.
(In reply to comment #25)
The error happens after entering username/password and closing the prompt with OK in the STR from comment 0.
Flags: blocking-calendar0.7?
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.
Attached patch proof of concept (obsolete) — Splinter Review
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.
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?
Attached file 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.
Attachment #279357 - Attachment mime type: application/octet-stream → text/plain
(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.

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 on attachment 277242 [details] [diff] [review]
check for onStartRequest

mvl, thanks for taking care of the real fix.
Attachment #277242 - Attachment is obsolete: true
Attachment #277242 - Flags: review?(mvl)
Assignee: sebo.moz → nobody
Status: ASSIGNED → NEW
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.
Version: Trunk → unspecified
Daniel, this is definitely a blocker (decision on the QA chat).
Flags: blocking-calendar0.7? → blocking-calendar0.7+
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+.
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.
(or a string stream, if that works better for you)
(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...
(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.
Attached patch missing unlocks (obsolete) — Splinter Review
Potentially unsafe code => leads to locked queue.
Attachment #280120 - Flags: review?(mvl)
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.
(In reply to comment #42)
Hmm, I have not encountered any problems using it in WCAP.
(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 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.
Attachment #280120 - Flags: review?(mvl) → review-
Attached patch cleaned patch (obsolete) — Splinter Review
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.
Assignee: nobody → mvl
Attachment #279356 - Attachment is obsolete: true
Status: NEW → ASSIGNED
Attachment #280158 - Flags: review?(daniel.boelzle)
Comment on attachment 280120 [details] [diff] [review]
missing unlocks

Moved review to bug 393387 which fits better.
Attachment #280120 - Attachment is obsolete: true
Attached patch updated patchSplinter Review
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.
Attachment #280158 - Attachment is obsolete: true
Attachment #280165 - Flags: review?(daniel.boelzle)
Attachment #280158 - Flags: review?(daniel.boelzle)
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
Attachment #280165 - Flags: review?(daniel.boelzle) → review+
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);
Status: ASSIGNED → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Daniel, is this bug really already fixed? I don't see a corresponding checkin.
damn, however I did that, I messed it up! sorry.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Status: REOPENED → NEW
patch checked in
Status: NEW → RESOLVED
Closed: 12 years ago12 years ago
Resolution: --- → FIXED
Target Milestone: --- → 0.7
+         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).
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!
Duplicate of this bug: 386734
Duplicate of this bug: 400051
You need to log in before you can comment on or make changes to this bug.