mscdex / node-imap

An IMAP client module for node.js.
MIT License
2.16k stars 380 forks source link

TypeError: Cannot read property of '_msg' of undefined #103

Closed j5bart closed 11 years ago

j5bart commented 12 years ago

If I leave my IMAP connection open to the server for a while and then try to retrieve emails after 'msgupdate' event is triggered, I get the following error:

/home/main/Jeeves/node_modules/imap/lib/imap.js:243 if (requests[0]._msg.headers[name] !== undefined) ^ TypeError: Cannot read property '_msg' of undefined at ImapConnection.connect.isUnsolicited (/home/main/Jeeves/node_modules/imap/lib/imap.js:243:32) at EventEmitter.emit (events.js:91:17) at MIMEParser.execute (/home/main/Jeeves/node_modules/imap/lib/mimeparser.js:96:14) at ondata (/home/main/Jeeves/node_modules/imap/lib/imap.js:194:24) at Socket.ondata (/home/main/Jeeves/node_modules/imap/lib/imap.js:256:16) at Socket.EventEmitter.emit (events.js:88:17) at TCP.onread (net.js:395:14)

Anyone else experienced this issue before?

Thanks,

Seb

mscdex commented 12 years ago

Can you provide simple code that reproduces the issue?

j5bart commented 12 years ago

It isn't easily reproduced. There is no problem most of the time, it just appears that requests[0] can occasionally be an undefined value... Looking at the source for imap.js, I couldn't spot this programatically.

I don't have an example I can share publicly just now, but I'll try to create code that reproduces the issue seperately.

I'll be in touch.

mscdex commented 12 years ago

Also make sure you're on the latest version (0.5.2 as of this writing).

One thing that is odd about your backtrace is that it's showing the same line number for two different things. Specifically, "isUnsolicited" is not on the same line where the TypeError is pointing to...

j5bart commented 12 years ago

Yeh, this confused me too! What is the isUnsolicited var for? Is it for events that are triggered externally by a different client (ie. not by this node-imap client)? My current version is 0.5.0 as was available from npm. I'll try an update just now.

j5bart commented 12 years ago

Updated to 0.5.2, error message changes slightly:

/home/main/Jeeves/node_modules/imap/lib/imap.js:242 if (requests[0]._headers ^ TypeError: Cannot read property '_headers' of undefined at ImapConnection.connect.isUnsolicited (/home/main/Jeeves/node_modules/imap/lib/imap.js:242:32) at EventEmitter.emit (events.js:91:17) at MIMEParser.execute (/home/main/Jeeves/node_modules/imap/lib/mimeparser.js:96:14) at ondata (/home/main/Jeeves/node_modules/imap/lib/imap.js:194:24) at Socket.ondata (/home/main/Jeeves/node_modules/imap/lib/imap.js:258:16) at Socket.EventEmitter.emit (events.js:88:17) at TCP.onread (net.js:395:14)

To maybe give a bit more insight, in debug mode I get the following output just prior to the error, which seems to suggest that it IS receiving the message? (FYI, I've had to sanitize some information)

Wed Sep 19 2012 11:38:10 GMT+0100 (BST): [parsing incoming] saw untagged SEARCH Wed Sep 19 2012 11:38:10 GMT+0100 (BST): <== 'A47 OK SEARCH completed.\r\n'

Wed Sep 19 2012 11:38:10 GMT+0100 (BST): [parsing incoming] saw tagged response Wed Sep 19 2012 11:38:10 GMT+0100 (BST): ==> A48 UID FETCH 18,19,20,21 (UID FLAGS INTERNALDATE BODYSTRUCTURE BODY.PEEK[])

Wed Sep 19 2012 11:38:11 GMT+0100 (BST): <== '* 4 FETCH (UID 18 FLAGS () INTERNALDATE "17-Sep-2012 14:04:44 +0100" BODYSTRUCTURE ("text" "plain" ("charset" "utf-8") NIL NIL "base64" 1872 24 NIL NIL "en-US" NIL) BODY[] {3125}\r\nReceived: from MAIL01.mydomain.co.uk\r\n ([fe80::b1bf:c1f7:1c00:2d00]) by MAIL01.mydomain.co.uk\r\n ([fe80::b1bf:c1f7:1c000:2d00%10]) with mapi id 14.02.0318.001; Mon, 17 Sep\r\n 2012 14:04:43 +0100\r\nFrom: Seb Bartholomew Seb@mydomain.co.uk\r\nTo: temp12092012 temp12092012@mydomain.co.uk\r\nSubject: RE: Send me back please\r\n Some more subject here.\r\nThread-Topic: Send me back please\r\n Some more subject here.\r\nThread-Index: AQHNlNQ2xe7eFjxUGE+fvaD9hoE+eZeOgoBw\r\nDate: Mon, 17 Sep 2012 14:04:11 +0100\r\nMessage-ID:\r\n 012365654E433744B7E2E63B93619E4C0B97F146@mail01.mydomain.co.uk\r\nReferences:\r\n e44255ab-1b11-4812-9405-6694fea499ee@mail01.mydomain.co.uk\r\nIn-Reply-To:\r\n e44255ab-1b11-4812-9405-6694fea499ee@mail01.mydomain.co.uk\r\nAccept-Language: en-GB, en-US\r\nContent-Language: en-US\r\nX-MS-Exchange-Organization-AuthAs: Internal\r\nX-MS-Exchange-Organization-AuthMechanism: 04\r\nX-MS-Exchange-Organization-AuthSource: mail01.mydomain.co.uk\r\nX-MS-Has-Attach:\r\nX-MS-Exchange-Organization-SCL: -1\r\nX-MS-TNEF-Correlator:\r\nContent-Type: text/plain; charset="utf-8"\r\nContent-Transfer-Encoding: base64\r\nMIME-Version: 1.0\r\n\r\nDQoNClNlYg0KD...[Truncated]...bmQgbWUgYmFjayBwbGVhc2U'

Wed Sep 19 2012 11:38:11 GMT+0100 (BST): <== 'Received: from mail01.mydomain.co.uk\r\n ([fe80::b1bf:c1f7:1c00:2d00]) by mail01.mydomain.co.uk\r\n ([fe80::b1bf:c1f7:1c00:2d00%10]) with mapi id 14.02.0318.001; Mon, 17 Sep\r\n 2012 14:04:43 +0100\r\nFrom: Seb Bartholomew Seb@clicknetworks.co.uk\r\nTo: temp12092012 temp12092012@clicknetworks.co.uk\r\nSubject: RE: Send me back please\r\n Some more subject here.\r\nThread-Topic: Send me back please\r\n Some more subject here.\r\nThread-Index: AQHNlNQ2xe7eFjxUGE+fvaD9hoE+eZeOgoBw\r\nDate: Mon, 17 Sep 2012 14:04:11 +0100\r\nMessage-ID:\r\n 012365654E433744B7E2E63B93619E4C0B97F146@mail01.mydomain.co.uk\r\nReferences:\r\n e44255ab-1b11-4812-9405-6694fea499ee@mail01.mydomain.co.uk\r\nIn-Reply-To:\r\n e44255ab-1b11-4812-9405-6694fea499ee@mail01.mydomain.co.uk\r\nAccept-Language: en-GB, en-US\r\nContent-Language: en-US\r\nX-MS-Exchange-Organization-AuthAs: Internal\r\nX-MS-Exchange-Organization-AuthMechanism: 04\r\nX-MS-Exchange-Organization-AuthSource: mail01.mydomain.co.uk\r\nX-MS-Has-Attach:\r\nX-MS-Exchange-Organization-SCL: -1\r\nX-MS-TNEF-Correlator:\r\nContent-Type: text/plain; charset="utf-8"\r\nContent-Transfer-Encoding: base64\r\nMIME-Version: 1.0\r\n\r\nDQoNClNlYg0KD...[Truncated]...bmQgbWUgYmFjayBwbGVhc2U'

mscdex commented 12 years ago

I don't see anything unusual in that debug output.

Am I correct in assuming your code is something like this?:

waitForMsgUpdate():
   searchForMessages():
     fetchAllFoundMessages()

Is that last line of debug output all you get right before the error is thrown?

Does this problem happen consistently when idling and receiving a 'msgupdate' event?

Also, what server software is this (should show in the greeting at the very beginning of the debug output)?

j5bart commented 12 years ago

Correct my code is approximately like you stated above.

At start, my code opens an imap connection and opens the 'INBOX' box with read-write permission (ie read-only=false),

It then searches for 'UNSEEN' messages in 'INBOX', collects these messages, processes them and then waits for any 'msgupdate' or 'mail' event to run the same function again.

If I update a message or send the INBOX a new message shortly after the initialisation above completes, there is no error. However, if I let the system sit for circa 10 minutes with no activity, and then send the INBOX a new email or update an existing message, the same procedure runs and crashes with above message.

It certainly feels like a timeout issue, however on the 'close' and 'end' events for the connection, I instruct the connection to run the .connect() and .openBox() procedure again (so I AM recycling the same connection, maybe this is root of problem?).

The server is a Microsoft Exchange 2010 server running IMAP 4rev1. Greeting looks like this:

Wed Sep 19 2012 14:17:48 GMT+0100 (BST): [connection] Connected to host. Wed Sep 19 2012 14:17:48 GMT+0100 (BST): <== '* OK The Microsoft Exchange IMAP4 service is ready.\r\n'

Wed Sep 19 2012 14:17:48 GMT+0100 (BST): [parsing incoming] saw untagged OK Wed Sep 19 2012 14:17:48 GMT+0100 (BST): ==> A1 CAPABILITY

Wed Sep 19 2012 14:17:48 GMT+0100 (BST): <== '* CAPABILITY IMAP4 IMAP4rev1 AUTH=NTLM AUTH=GSSAPI AUTH=PLAIN STARTTLS UIDPLUS CHILDREN IDLE NAMESPACE LITERAL+\r\nA1 OK CAPABILITY completed.\r\n'

Wed Sep 19 2012 14:17:48 GMT+0100 (BST): [parsing incoming] saw untagged CAPABILITY Wed Sep 19 2012 14:17:48 GMT+0100 (BST): <== 'A1 OK CAPABILITY completed.\r\n'

Wed Sep 19 2012 14:17:48 GMT+0100 (BST): [parsing incoming] saw tagged response Wed Sep 19 2012 14:17:48 GMT+0100 (BST): ==> A2 LOGIN "temp12092012" "[password]"

Wed Sep 19 2012 14:17:48 GMT+0100 (BST): <== 'A2 OK LOGIN completed.\r\n'

Wed Sep 19 2012 14:17:48 GMT+0100 (BST): [parsing incoming] saw tagged response Wed Sep 19 2012 14:17:48 GMT+0100 (BST): ==> A3 CAPABILITY

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): <== '* CAPABILITY IMAP4 IMAP4rev1 AUTH=NTLM AUTH=GSSAPI AUTH=PLAIN STARTTLS UIDPLUS CHILDREN IDLE NAMESPACE LITERAL+\r\nA3 OK CAPABILITY completed.\r\n'

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): [parsing incoming] saw untagged CAPABILITY Wed Sep 19 2012 14:17:49 GMT+0100 (BST): <== 'A3 OK CAPABILITY completed.\r\n'

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): [parsing incoming] saw tagged response Wed Sep 19 2012 14:17:49 GMT+0100 (BST): ==> A4 NAMESPACE

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): <== '* NAMESPACE (("" "/")) NIL NIL\r\nA4 OK NAMESPACE completed.\r\n'

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): [parsing incoming] saw untagged NAMESPACE Wed Sep 19 2012 14:17:49 GMT+0100 (BST): <== 'A4 OK NAMESPACE completed.\r\n'

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): [parsing incoming] saw tagged response Wed Sep 19 2012 14:17:49 GMT+0100 (BST): ==> A5 LIST "" ""

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): <== '* LIST (\Noselect \HasChildren) "/" ""\r\nA5 OK LIST completed.\r\n'

Wed Sep 19 2012 14:17:49 GMT+0100 (BST): [parsing incoming] saw untagged LIST Wed Sep 19 2012 14:17:49 GMT+0100 (BST): <== 'A5 OK LIST completed.\r\n'

mscdex commented 12 years ago

Hmmm, can you try and see if not recycling the ImapConnection object fixes things for you? This will help narrow things down possibly...

ChrisGitIt commented 11 years ago

Hi, i have the same problem thats described above. I'm opening one box, then closing it and want to open the second box. I tried not to "recycle" via:

...
fetch.on('end', function() {
  imap.logout(); // and/or imap.closeBox();
  getBox('Deleted Messages',function(err, mailbox) {
    ...
  )};
});

Somehow no luck. Any suggestions for this problem? I can't get the point whats going wrong. Somewhere on the way, the request[0]._headers get lost ...

Thanks in advance for every hint or tip! I'm currently in a interesting project and have no other way around ...

Greets,

Chris

mscdex commented 11 years ago

@ChrisGitIt Can you post the code you are using and provide the backtrace you get when using the master branch?

ChrisGitIt commented 11 years ago

Problem solved!

First of all thanks for the support! Soon after my post i got the suggestion via mail to maintain the connection. So the following code (taken from the examples):

function openInbox(cb) {
    imap.connect(function(err) {
      if (err) die(err);
      imap.openBox('INBOX', false, cb);
    });
  }

changed to:

function openInbox(callback) {
        if(!imap._state.isReady) {
            imap.connect(function(err) {
                if (err) die(err);
                imap.openBox('INBOX', false, callback);
            });
        } else {
            imap.openBox(name, false, callback);
        }
    }

resolves the problem. I'm not sure if there are "Ready States" in-between (like in Ajax calls) but so far this helps me out to go ahead with my project, a html5 Webmail client ...

Greets and thanks to all!

Chris

matadan commented 11 years ago

I've encountered this exact same issue. I tried Chris's solution but it had no effect. The resolution that worked for me was not to reuse the imap connection between logouts and create a fresh imap connection for each use.

mscdex commented 11 years ago

@matadan Can you clarify a bit? After you called logout() (without a callback) you could not call connect() again immediately on the same ImapConnection object? If this is the case (no logout callback), can you try the master branch with this patch applied and then try using logout(true) instead?