Closed Bug 1159777 Opened 10 years ago Closed 9 years ago

Strange Failure of inboxInputStream = do_QueryInterface(m_outFileStream) in nsPop3Sink.cpp

Categories

(MailNews Core :: Networking: POP, defect)

x86_64
Linux
defect
Not set
major

Tracking

(Not tracked)

RESOLVED WORKSFORME

People

(Reporter: ishikawa, Unassigned)

Details

Failure of inboxInputStream = do_QueryInterface(m_outFileStream); After refreshing the C-C source tree, "python client.py checkout" Starting today, I got a strange error. I was testing file I/O errors, and I began testing the less used code path of downloadin to a temporary file first, then letting TB append/copy the temporary file to the main inbox file. In TB's preference, we have to set non-existing mailnews.downloadToTempFile to true to activate this behavior. I set this about a week ago, and I was wondering if this path is really executed, until today when I got an error panel that says either I don't have a permission, or file space is low, etc. skip this message, etc. As I investigated, I found that the following code path produced a null inboxInputStream (so I was using the temporary file download scheme, but I did not get the error before somehow.) nsCOMPtr <nsIInputStream> inboxInputStream = do_QueryInterface(m_outFileStream); rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); The code is in the following path. http://mxr.mozilla.org/comm-central/source/mailnews/local/src/nsPop3Sink.cpp#787 775 if (m_downloadingToTempFile) 776 { 777 // close file to give virus checkers a chance to do their thing... 778 m_outFileStream->Flush(); 779 m_outFileStream->Close(); 780 m_newMailParser->FinishHeader(); 781 // need to re-open the inbox file stream. 782 bool exists; 783 m_tmpDownloadFile->Exists(&exists); 784 if (!exists) 785 return HandleTempDownloadFailed(aMsgWindow); 786 * 787 nsCOMPtr <nsIInputStream> inboxInputStream = do_QueryInterface(m_outFileStream); 788 rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); 789 NS_ENSURE_SUCCESS(rv, HandleTempDownloadFailed(aMsgWindow)); 790 if (m_outFileStream) 791 { Line 787 looks very innocent. I am curios. Has anyone enabled this mailnews.downloadToTempFile and still have TB functioning correctly? BTW, the check of 790 if (m_outFileStream) is wrong. I think it ought to be if (inboxInputStream) instead. My local version of nsPop3Sink.cpp has more error checks in the same path. See below. if (m_downloadingToTempFile) { NS_WARNING("(debug) m_downloadingToTempFile path in IncorporateComplete "); // close file to give virus checkers a chance to do their thing... nsresult rv2 = m_outFileStream->Close(); // We can't null this yet m_outFileStream = nullptr; NS_WARN_IF_FALSE(NS_SUCCEEDED(rv2), "m_outFileStream->Close() failed;"); // Check I/O error. nsresult rv3 = m_newMailParser->FinishHeader(); if (NS_FAILED(rv3)) { #if DEBUG fprintf(stderr, "%d: m_newMailParser->FinishHeader() returned 0x%08x\n", __LINE__, rv3); #endif NS_ERROR("m_newMailparser->FinishHeader() failed."); } // // Should we not set // m_outFileStream = nullptr // irrespective of whether Close() failed or not? // No, not here yet because we may use this variable below. // Add a proper error check. if (NS_FAILED(rv2) || NS_FAILED(rv3)) { NS_WARNING("(debug): show error dialog."); #if DEBUG fflush(stdout); fprintf(stderr,"Error handling... case 1\n"); #endif return HandleTempDownloadFailed(aMsgWindow); } // need to re-open the inbox file stream. // Note that a virus checker might have removed the temporary file! bool exists; m_tmpDownloadFile->Exists(&exists); if (!exists) { #if DEBUG fflush(stdout); fprintf(stderr,"Error handling... case 2\n"); #endif return HandleTempDownloadFailed(aMsgWindow); } // Natural question from a confused reader of this code: // why a mixture of (inboxInputStream|m_outFilestream) below? // Answer: This is because we are going to READ the temporary // file into which we WROTE the downloaded message for the // final appending/incorporation into the mail store. nsCOMPtr <nsIInputStream> inboxInputStream = do_QueryInterface(m_outFileStream); rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); #if DEBUG if (NS_FAILED(rv)) { fflush(stdout); fprintf(stderr,"m_outFileStream=%p, inboxInputStream=%p\n", (void *) m_outFileStream, (void *) inboxInputStream); fprintf(stderr,"Error handling... case 3\n"); } #endif NS_ENSURE_SUCCESS(rv, HandleTempDownloadFailed(aMsgWindow)); m_outFileStream = nullptr; // finally. Catch reuse with SIGSEGV // Recall we are in if (m_downloadingToTempFile) branch. // // Is the following check actually meant for inboxInputStream? // // m_outFileStream->Close() has already been called about a dozen lines abobe. // inboxInputStream is created in MsgReopenFileStream only a few lines above, and // for an unknown reason it may not obtain ... // Wait a second, MsgReopenFileStream does not change the value of inboxInputStream // at all. // If we want the check for inboxInputStream, that should be right // after do_QueryInterface call before MsgReopenFileStream. // Luckily for us, MsgReopenFileStream checks for the null filestream passed. // We can see that m_outFileStream should NOT be nullptr here since // it is used as in m_outFileStream->Close() in the path leading to this place. // If it is nullptr, TB has crashed then. // Hmm... // So finally, I decided this is the check for inboxInuptStream if (inboxInputStream) { I wonder what has changed or if the code mentioned here worked in other people's environment.
Component: Untriaged → Networking: POP
Product: Thunderbird → MailNews Core
Years ago I wrote a unit test that uses this option: /mailnews/base/test/unit/test_quarantineFilterMove.js You might check to see if this test executes your code path. The best way to investigate this would be to modify the unit test to exercise different code paths.
As to the code analysis: "BTW, the check of 790 if (m_outFileStream) is wrong. I think it ought to be if (inboxInputStream) instead." I was the last one to change that line of code (many years ago) but that was just changing the indent from a previous incarnation. I agree that if inputInputStream can be null while m_outFileStream is non-null, then changing the check might make sense. But I would need to look more thoroughly at what this code does, and I don't have time to do that at the moment.
(In reply to Kent James (:rkent) from comment #1) > Years ago I wrote a unit test that uses this option: > > /mailnews/base/test/unit/test_quarantineFilterMove.js > > You might check to see if this test executes your code path. The best way to > investigate this would be to modify the unit test to exercise different code > paths. Thank you for the pointer. This is great. (In reply to Kent James (:rkent) from comment #2) > As to the code analysis: > > "BTW, the check of > 790 if (m_outFileStream) > is wrong. I think it ought to be > if (inboxInputStream) > instead." > > I was the last one to change that line of code (many years ago) but that was > just changing the indent from a previous incarnation. I agree that if > inputInputStream can be null while m_outFileStream is non-null, then > changing the check might make sense. But I would need to look more > thoroughly at what this code does, and I don't have time to do that at the > moment. I know you are busy just before the pending release of new version. Many people are. For the original issue, I found out that it is indeed the case that 787 nsCOMPtr <nsIInputStream> inboxInputStream = do_QueryInterface(m_outFileStream); fails if m_outFileStream is transformed into a buffered output stream. Then inboxInputStream is nullptr. But *BEFORE* m_outFileStream is transformed to a buffered output stream, the above succeeds and we have non-null inboxInputStream. So I create a value of inboxInputStream before m_outFileStream is turned into a buffered output stream, and use the value later when I need it for 788 rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); This issue has become apparent only because I tried to enable buffering when we write to the local file (in this code path, it is a temporary file). Upon WRITING the message fully and close it so that anti-virus software can do its job, we NOW NEED TO READ from the same file. I have a patch to do just that (creating inboxInputStream before m_outFileStream is turned into a buffered output stream and using the value later). I will upload this shortly. TIA
What does the line actually do? nsCOMPtr <nsIInputStream> inboxInputStream = do_QueryInterface(m_outFileStream); What does the inputstream have to do with the outputstream? The latter one is closed and we do not need it anymore. We create a new input stream and initialize it from the file (a nsIFile). rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); So why does creating inboxInputStream query interface of the m_outFileStream ? Maybe that can be removed?
(In reply to :aceman from comment #4) Thank you for your comment. > What does the line actually do? > nsCOMPtr <nsIInputStream> inboxInputStream = > do_QueryInterface(m_outFileStream); That is a great question. I was as puzzled as you were when I saw it for the first time and thus put in a comment about it in my local copy. Anyway, the reason this statement fails to produce a non-nullptr inboxInputStream is discussed in answers to my question in dev-platfrom mailing list (newsgroup). https://groups.google.com/forum/#!topic/mozilla.dev.platform/8NmidV-eYtc Short answer is, it is a dynamical type cast and once buffered, an output file stream object cannot be dynamically type cast to input stream object in today's class definitions. That is how the particular buffered output stream class is implemented. > > What does the inputstream have to do with the outputstream? The latter one > is closed and we do not need it anymore. We create a new input stream and > initialize it from the file (a nsIFile). > rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); > > So why does creating inboxInputStream query interface of the m_outFileStream > ? Maybe that can be removed? If MsgReopenFileStream() can creates a new file stream in the second argument then it is fine to remove the do_QueryInterface(). But, no. MsgReopenFileStream() expects an non-nullptr argument is passed to it. http://mxr.mozilla.org/comm-central/source/mailnews/base/util/nsMsgUtils.cpp#1435 1435 nsresult MsgReopenFileStream(nsIFile *file, nsIInputStream *fileStream) 1436 { 1437 nsMsgFileStream *msgFileStream = static_cast<nsMsgFileStream *>(fileStream); 1438 if (msgFileStream) 1439 return msgFileStream->InitWithFile(file); 1440 else 1441 return NS_ERROR_FAILURE; 1442 } So we must have a valid non-nullptr filestream to start with, and that is the reason for do_QueryInterface(), I think. In the end, I have changed the code so that before m_outFileStream is transformed into a buffered stream dynamically (Yes, I want to make the output buffered for better I/O throughtput) >nsCOMPtr <nsIInputStream> inboxInputStream = do_QueryInterface(m_outFileStream); is executed and the non-nullptr inboxInputStream is saved into a new struct field of class nsPop3Sink m_inboxInputStream and this saved value used for the subsequent processing starting with > rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream) and thereafter. All is well now :-) Both downloading to Inbox directly and downloading to a temporary file and then copy/appending to Inbox works fine (with buffering even) for Pop3 download. Imap-side is not heavily tested, but under normal conditions there are no ill-effect after my trying to harden Pop3 error handling. Isn't this great? TIA PS: BTW I started to test an imap user account under erratic network conditions (unplug network) to simulate real-world network errors when one's profile is on a remote file system, and In the first couple of tests, I already got a nice set of errors such as: (1) [14066] ###!!! ASSERTION: Oops, thread is still running. : '!m_imapThreadIsRunning', file /REF-COMM-CENTRAL/comm-central/mailnews/imap/src/nsImapProtocol.cpp, line 580 (This I never saw in pop3 testing. So unlike pop3 download, imap seems to use multiple threads for download? I expect difficult debugging sessions here.) (2) [14066] ###!!! ASSERTION: m_tempMessageStream->Write(adoptedMessageLine, ...) failed.: 'Error', file /REF-COMM-CENTRAL/comm-central/mailnews/imap/src/nsImapMailFolder.cpp, line 4635 [14066] WARNING: nsBufferedOutputStream::Write returns immediately (mStream=null): file /REF-COMM-CENTRAL/comm-central/mozilla/netwerk/base/nsBufferedStreams.cpp, line 672 (Many repetitions of the pair of messages) The line number 4635 is off from the line number in C-C source tree due to my local addition of error checks. The first line is from the error check of line 4596 (in my local check, I checked for short-write, too.) 4589 if (m_tempMessageStream) 4590 { 4591 nsCOMPtr <nsISeekableStream> seekable (do_QueryInterface(m_tempMessageStream)); 4592 if (seekable) 4593 seekable->Seek(PR_SEEK_END, 0); 4594 rv = m_tempMessageStream->Write(adoptedMessageLine, 4595 PL_strlen(adoptedMessageLine), &count); 4596 NS_ENSURE_SUCCESS(rv, rv); 4597 } >[14066] WARNING: nsBufferedOutputStream::Write returns immediately (mStream=null): file /REF-COMM-CENTRAL/comm-central/mozilla/netwerk/base/nsBufferedStreams.cpp, line 672 The second line warning is from my locally modified Write:: Bug 1120046 - RFC mozilla/netwerk/base/src/nsBufferedStreams.cpp: better error reporting and maybe adding thread-race lock I added code to return early when mStream is null (meaning the stream has already been closed.) I better land an improved patch (no need for thread-safety... Hmm... Does imap really use multiple threads?) in the above bug ASAP. NS_IMETHODIMP nsBufferedOutputStream::Write(const char *buf, uint32_t count, uint32_t *result) { nsresult rv = NS_OK; uint32_t written = 0; *result = 0; if (!mStream) { // Flush() returns NS_OK in this case ! See Flush() below. // We better catch the failure ASAP. #if DEBUG NS_WARNING("nsBufferedOutputStream::Write returns immediately (mStream=null)"); #endif return NS_BASE_STREAM_CLOSED; } while (count > 0) { uint32_t amt = std::min(count, mBufferSize - mCursor); if (amt > 0) { memcpy(mBuffer + mCursor, buf + written, amt); written += amt; count -= amt; mCursor += amt; if (mFillPoint < mCursor) mFillPoint = mCursor; } else { NS_ASSERTION(mFillPoint, "iloop in nsBufferedOutputStream::Write!"); rv = Flush(); if (NS_FAILED(rv)) { #if DEBUG NS_WARNING("Flush returned error in nsBufferedOutputStream::Write"); #endif break; } } } *result = written; return (written > 0) && NS_SUCCEEDED(rv) ? NS_OK : rv; } So basically imap code tries to keep writing to already closed stream (closed maybe due to error handling) without realizing it is closed! It ought to have realized there was an error and file stream was closed and thus return to top-level through error handler. Definitely a bug somewhere! (OK, so the error handler may have forgotten to stop this download thread, maybe?) (3) (debug) nsBufferedStream::Close() called.: mStream=0x(nil), /REF-COMM-CENTRAL/comm-central/mozilla/netwerk/base/nsBufferedStreams.cpp:97 --DOMWINDOW == 23 (0x340ffa0) [pid = 16346] [serial = 28] [outer = (nil)] [url = chrome://messenger/content/msgAccountCentral.xul] --DOMWINDOW == 22 (0x3863cc0) [pid = 16346] [serial = 30] [outer = (nil)] [url = https://www.mozilla.org/en-US/thunderbird/nightly/start/?uri=/thunderbird/start/&locale=en-US&version=40.0a1&os=Linux&buildid=20150502033214] Not specifically handled errno=112 nsMsgDBFolder.cpp:887: nsMsgDBFolder::GetMsgInputStream: msgStore->GetMsgInputStream(this, ...) returned error rv=80004005 [16346] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /REF-COMM-CENTRAL/comm-central/mailnews/base/util/nsMsgDBFolder.cpp, line 890 [16346] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /REF-COMM-CENTRAL/comm-central/mailnews/local/src/nsMailboxProtocol.cpp, line 192 Not specifically handled errno=112 Not specifically handled errno=112 [16346] WARNING: NS_ENSURE_TRUE(rv == NS_MSG_ERROR_FOLDER_SUMMARY_MISSING) failed: file /REF-COMM-CENTRAL/comm-central/mailnews/db/msgdb/src/nsMsgDatabase.cpp, line 391 [16346] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520006: file /REF-COMM-CENTRAL/comm-central/mailnews/imap/src/nsImapMailFolder.cpp, line 606 Not specifically handled errno=112 Not specifically handled errno=112 [16346] WARNING: NS_ENSURE_TRUE(rv == NS_MSG_ERROR_FOLDER_SUMMARY_MISSING) failed: file /REF-COMM-CENTRAL/comm-central/mailnews/db/msgdb/src/nsMsgDatabase.cpp, line 391 You see the errno 112 in the excerpt above. >Not specifically handled errno=112 That is EHOSTDOWN on my local linux. This is printed by a locally added line in the conversion from errno to NS_* type error values. Not all errno values are converted to meaningful value today. So EHOSTDOWN is changed to a very generic NS_ERROR number. Bug 1126881 - Mapping of errno to NS_* macros (nsresultForErrno(int aErr)) is not as complete as mapping to PR_* macros (Wait is the line printed in the conversion to PR_* macros? Anyway, you get the idea.) In the presence of hard network error (EHOSTDOWN), we encounter a missing folder summary. Naturally. I wish thunderbird can convey to the user that we are experiencing a network error by a dialog or something. Otherwise a strange error may result but it may not be clear to the user initially. Failure to convert EHOSTDOWN (errno=112) to a meaningful error suggests that TB is not doing anything for user-friendly error reporting :-( But these are imap-related issues. I will report these in new bugzillas if they have not been reported.
(In reply to ISHIKAWA, Chiaki from comment #5) > But, no. MsgReopenFileStream() expects an non-nullptr argument is passed to > it. > http://mxr.mozilla.org/comm-central/source/mailnews/base/util/nsMsgUtils. > cpp#1435 > > 1435 nsresult MsgReopenFileStream(nsIFile *file, nsIInputStream *fileStream) > 1436 { > 1437 nsMsgFileStream *msgFileStream = static_cast<nsMsgFileStream > *>(fileStream); > 1438 if (msgFileStream) > 1439 return msgFileStream->InitWithFile(file); > 1440 else > 1441 return NS_ERROR_FAILURE; > 1442 } > > So we must have a valid non-nullptr filestream to start with, and that is > the reason > for do_QueryInterface(), I think. > So why isn't this enough? nsCOMPtr<nsIInputStream> inboxInputStream; MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); What property does input stream need to copy from the output stream? I still do not understand why it references the output stream in any way.
(In reply to :aceman from comment #6) [...] > So why isn't this enough? > nsCOMPtr<nsIInputStream> inboxInputStream; > MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); > Like I said, I was very puzzled myself. From the comment of Boris Zbarsky in the thread: https://groups.google.com/forum/#!topic/mozilla.dev.platform/8NmidV-eYtc (I asked if "nsCOMPtr <nsIInputStream> inboxInputStream;" is supposed to fail.) > Sure. You're taking an _output_ stream and QIing it to > nsI_Input_Stream. > > It might happen that some objects implement both interfaces (and looks > like nsMsgFileStream does). The object returned by > NS_BufferOutputStream does not: it's an output stream, but not an input > stream. So before the buffering was introduced, it was OK, but once buffering is introduced, it is no longer possible. Joshua Cranmer: > In short, yes. What happens is that the original m_outFileStream happens > to be of type nsFileStreams (or something like that), which inherits (cf. Note "something like that." It is really tough to figure out the type of data we are dealing with at run-time by a quick browsing. That is why I think bug fixing is so difficult, but I digress.) > from both nsIInputStream and nsIOutputStream. When you wrap that in a > buffered output stream, the resulting type of m_outFileStream is of > nsBufferedOutputStream, which does not inherit nsIInputStream; therefore > the cast to nsIInputStream fails. So it is inevitable that the assignment fails. So Instead, I tried this as you suggested. nsCOMPtr <nsIInputStream> inboxInputStream; rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); This simply doesn't work. It fails at run-time. MsgReopenFileStream failed: rv = 0x80004005 This is a generic error. I suspect that there is something wrong in the manner initialization works. Maybe "Re" in "Reopen" may have something to do with needing to use an already established stream for this function to succeed. This observation may be the answer to your folowing question. > What property does input stream need to copy from the output stream? I still > do not understand why it references the output stream in any way. So I asked myself if there is a function that creates a stream for message reading (Msg*something*) from scratch. Looking at how m_outFileStream is created, rv = MsgGetFileStream(m_tmpDownloadFile, getter_AddRefs(m_outFileStream)); I tried this. nsCOMPtr <nsIInputStream> inboxInputStream; // = do_QueryInterface(m_outFileStream); // rv = MsgReopenFileStream(m_tmpDownloadFile, inboxInputStream); rv = MsgGetFileStream(m_tmpDownloadFile, getter_AddRefs(inboxInputStream)); This does not even compile, though. MsgGetFileStream() seems to expects nsIOutputStream**; See the compilation error below. It may be that if we lift the restriction of -fpermissive, we may be able to compile, but that is the required option in the build. --- quote compilation error Note: rebuild with "make VERBOSE=1 all-local" to show all compiler parameters. nsPop3Sink.o /REF-COMM-CENTRAL/comm-central/mailnews/local/src/nsPop3Sink.cpp: In member function ‘virtual nsresult nsPop3Sink::IncorporateComplete(nsIMsgWindow*, int32_t)’: /REF-COMM-CENTRAL/comm-central/mailnews/local/src/nsPop3Sink.cpp:995:80: error: invalid user-defined conversion from ‘nsGetterAddRefs<nsIInputStream>’ to ‘nsIOutputStream**’ [-fpermissive] rv = MsgGetFileStream(m_tmpDownloadFile, getter_AddRefs(inboxInputStream)); ^ In file included from ../../../dist/include/nsComponentManagerUtils.h:11:0, from ../../../dist/include/nsIServiceManager.h:130, from ../../../dist/include/msgCore.h:21, from /REF-COMM-CENTRAL/comm-central/mailnews/local/src/nsPop3Sink.cpp:6: ../../../dist/include/nsCOMPtr.h:1189:3: note: candidate is: nsGetterAddRefs<T>::operator void**() [with T = nsIInputStream] <near match> operator void**() ^ ../../../dist/include/nsCOMPtr.h:1189:3: note: no known conversion from ‘void**’ to ‘nsIOutputStream**’ --- end quote So that is why I gave up and decided to follow the original steps albeit I would move the postion of > nsCOMPtr <nsIInputStream> inboxInputStream = do_QueryInterface(m_outFileStream); to a place BEFORE m_oupFileStream is turned into a buffered stream. It works with the change now. cf. I don't want to change the Msg*() functions. I noticed that there seems to be an operation mode where TB reads from a hashed data structure (maybe an in-core cache?) instead of a file. (The reading function is overlaid with the file read and such hash table read. I was checking which read/write/close needs to checked for error return and stumbled upon a few such calls. They don't have the same semantics with the purely file operation, I think.) So I don't want to touch these functions unless I have a better understanding of every data structure used in the download code, etc. Unfortunately, that is way beyond the hobbyist programmer's domain :-(. That is why I dealt with this issue by moving the assignment elsewhere where it succeeds. During the IMAP testing under network error conditiosn, if I find it necessary to open a file stream for reading from scratch, I may come back to this bug and might want to create something for MsgGetFileStreamForReading() or whatever... TIA
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
(we use worksforme when the issue wasn't resolved by a known patch)
Resolution: FIXED → WORKSFORME
You need to log in before you can comment on or make changes to this bug.