1965652 - comm/mailnews/mime/test/unit/test_mimeStreaming.js - Is calling onDataAvailable() on already closed stream OK?

Status: NEW

(MailNews Core :: MIME, defect)

Description

[ISHIKAWA, Chiaki]

I am running xpcshell test locally under linux on my PC.
Locally, I have patched PR_Close(), PR_Read(), etc. to check for erroneous calls to streams which have ALREADY been closed and raise error of NS_BASE_STREAM_CLOSED is returned when that happens.
I certainly did many years ago, and some of these checks may be already inside M-C tree, but not all of them, I think.

I am reporting that in the test comm/mailnews/mime/test/unit/test_mimeStreaming.js,
there is a the following routine. It is short and I am quoting it.
https://searchfox.org/comm-central/source/mailnews/mime/test/unit/test_mimeStreaming.js#70

  /* okay, our onDataAvailable should actually never be called.  the stream
     converter is actually eating everything except the start and stop
     notification. */
  // nsIStreamListener part
  onDataAvailable(aRequest, aInputStream, aOffset, aCount) {
    if (this._stream === null) {
      this._stream = Cc["@mozilla.org/scriptableinputstream;1"].createInstance(
        Ci.nsIScriptableInputStream
      );
      this._stream.init(aInputStream);   <====  raises NS_BASE_STREAM_CLOSED (!)
    }
    this._stream.read(aCount);
  },
};

Well, the comment says " okay, our onDataAvailable should actually never be called. "
But in this test, it is called. I know it because in my local test using FULL DEBUG version of C-C TB,
the read on the line 77 returns NS_BASE_STREAM_CLOSED in the called read() routine with my additional checks for closed stream.
https://searchfox.org/comm-central/source/mailnews/mime/test/unit/test_mimeStreaming.js#77

00:00.73 INFO "CONSOLE_MESSAGE: (error) [JavaScript Error: "NS_BASE_STREAM_CLOSED: Component returned failure code: 0x80470002 (NS_BASE_STREAM_CLOSED) [nsIScriptableInputStream.read]" {file: "/NEW-SSD/ASAN-OBJ-DIR/objdir-tb3/_tests/xpcshell/comm/mailnews/mime/test/unit/test_mimeStreaming.js" line: 77}]
onDataAvailable@/NEW-SSD/ASAN-OBJ-DIR/objdir-tb3/_tests/xpcshell/comm/mailnews/mime/test/unit/test_mimeStreaming.js:77:18

There is obviously logical error in the test, and that is causing this error situation. We really should not call read() on
already closed stream.

But I have no idea how to fix the issue. And for that matter, I am not sure what the test is trying to check.
The error seems to have been with the source tree for many years.
But with my local log summarizer script, I get the following output and was wondering what the error is all about.

	----------------------------------------
	BASE_STREAM as in NS_ERROR_BASE_STREAM_CLOSED
	----------------------------------------
      1 error: /NEW-SSD/ASAN-OBJ-DIR/objdir-tb3/_tests/xpcshell/comm/mailnews/mime/test/unit/test_mimeStreaming.js, line 77: NS_BASE_STREAM_CLOSED: Component returned failure code: 0x80470002 (NS_BASE_STREAM_CLOSED) [nsIScriptableInputStream.read]
      1 "CONSOLE_MESSAGE: (error) [JavaScript Error: "NS_BASE_STREAM_CLOSED: Component returned failure code: 0x80470002 (NS_BASE_STREAM_CLOSED) [nsIScriptableInputStream.read]" {file: "/NEW-SSD/ASAN-OBJ-DIR/objdir-tb3/_tests/xpcshell/comm/mailnews/mime/test/unit/test_mimeStreaming.js" line: 77}]

Someone in the know might want to fix this hidden error.
Hidden because the stock M-C PR_Read() and friends don't bother to check this NS_BASE_STREAM_CLOSED condition early and report the logical error at early stage.
So you don't see it on treeherder.

I encountered such errors of invoking read/write to already closed stream while I worked on introducing better I/O error checks when low-level I/O routines were called to introduce the buffered write to TB's mesage writing function.
Thus I installed the stricter check and removed the errors lurking in the C++/C code when an I/O error happened.

This particular test seems to intentionally calling the logically dubious read() on already closed stream. But for what?

Comment 1

[Kai Engert [:KaiE:]]

This probably doesn't qualify for tracking as "tb140found".
It's a kind of code inconsistency that probably has been around for a long time, and shouldn't be user noticeable? (And if it is, this probably isn't new in 140.)

Comment 2

[Wayne Mery (:wsmwk)]

(In reply to Kai Engert [:KaiE:] from comment #1)

This probably doesn't qualify for tracking as "tb140found".

It was done as a bulk change. I agree. Thanks for calling this out.