Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error thrown every time logout is called #161

Closed
shunkica opened this issue Jan 16, 2024 · 6 comments · Fixed by #162
Closed

Error thrown every time logout is called #161

shunkica opened this issue Jan 16, 2024 · 6 comments · Fixed by #162

Comments

@shunkica
Copy link

shunkica commented Jan 16, 2024

Describe the bug
Every time I call logout() on the client an error is thrown, even though all the actions have been completed successfully.

To Reproduce
Steps to reproduce the behavior:

const client = new ImapFlow(options);
await client.connect();
await client.logout();
await new Promise(resolve => setTimeout(resolve, 1000));

Versions
Node v20
imapflow v1.0.147

Additional context

{"level":20,"time":1705392278030,"pid":21924,"hostname":"fedora","component":"imap-connection","cid":"14nqen3027ycbmma2jkb","src":"s","msg":"6 LOGOUT","cid":"14nqen3027ycbmma2jkb"}
{"level":10,"time":1705392278050,"pid":21924,"hostname":"fedora","component":"imap-connection","cid":"14nqen3027ycbmma2jkb","msg":"Connection closed","cid":"14nqen3027ycbmma2jkb"}
{"level":40,"time":1705392278050,"pid":21924,"hostname":"fedora","component":"imap-connection","cid":"14nqen3027ycbmma2jkb","err":{"type":"Error","message":"Connection not available","stack":"Error: Connection not available\n at ImapFlow.close (/home/user/DevProjects/WebstormProjects/plin-udocit/node_modules/.pnpm/imapflow@1.0.147/node_modules/imapflow/lib/imap-flow.js:1437:32)\n at TLSSocket._socketEnd (/home/user/DevProjects/WebstormProjects/plin-udocit/node_modules/.pnpm/imapflow@1.0.147/node_modules/imapflow/lib/imap-flow.js:640:22)\n at TLSSocket.emit (node:events:526:35)\n at endReadableNT (node:internal/streams/readable:1589:12)\n at processTicksAndRejections (node:internal/process/task_queues:82:21)"},"cid":"14nqen3027ycbmma2jkb","msg":"Connection not available"}
{"level":20,"time":1705392278054,"pid":21924,"hostname":"fedora","component":"imap-connection","cid":"14nqen3027ycbmma2jkb","src":"s","msg":"* BYE Logging out","cid":"14nqen3027ycbmma2jkb"}
{"level":20,"time":1705392278054,"pid":21924,"hostname":"fedora","component":"imap-connection","cid":"14nqen3027ycbmma2jkb","src":"s","msg":"6 OK Logout completed (0.001 + 0.000 secs).","cid":"14nqen3027ycbmma2jkb"}

Possible cause
The connection is closed before the server has a chance to respond to the logout request.

@andris9
Copy link
Collaborator

andris9 commented Jan 16, 2024

I can not reproduce it. Getting this error means that there is still something in the execution pipeline when the socket is closed. You should check what exactly it is here

@shunkica
Copy link
Author

shunkica commented Jan 16, 2024

I can not reproduce it. Getting this error means that there is still something in the execution pipeline when the socket is closed. You should check what exactly it is here

This is my test, and the error appears every time:

describe('imapflow', () => {
    let options: ImapFlowOptions = {
        host: keys.mailHost,
        port: keys.mailPort,
        secure: true,
        auth: {
            user: keys.mailUser,
            pass: keys.mailPass
        }
    }

    it('throws the error', async () => {
        const client = new ImapFlow(options);
        await client.connect();
        await client.logout();
        await new Promise(resolve => setTimeout(resolve, 1000));
    });
});

This is the request in the pipeline:

{
  "command": "LOGOUT",
  "options": {}
}

@andris9
Copy link
Collaborator

andris9 commented Jan 16, 2024

Which Node version are you using? I'm not able to reproduce this behaviour at all. Logout is always processed before TCP close.

@shunkica
Copy link
Author

shunkica commented Jan 16, 2024

Which Node version are you using? I'm not able to reproduce this behaviour at all. Logout is always processed before TCP close.

I am on node v20.10.0 on my machine, but the error also appears in the node:20-alpine container.

The server is running dovecot.

@shunkica
Copy link
Author

shunkica commented Jan 16, 2024

I can confirm that v1.0.148 fixed the issue.

FWIW I created a account on a free email service and tried to reproduce with v1.0.147 but couldn't.
Looks like the issue only happened with the Dovecot IMAP server.

@andris9
Copy link
Collaborator

andris9 commented Jan 16, 2024

It was a race condition where the TCP close event was processed before the server response message for LOGOUT, so it was not so much about the specific server but timing, which is unpredictable.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants