haraka / Haraka

A fast, highly extensible, and event driven SMTP server
https://haraka.github.io
MIT License
5.09k stars 662 forks source link

Error: Callback was already called. #1995

Closed sstevan closed 7 years ago

sstevan commented 7 years ago

Issue with HTTP API (splitting #1993 )

I'm trying to utilize HTTP API to make Haraka deliver raw messages.

Here's the sender plugin with send-raw route:

const fs = require("fs");
const util = require("util");
const md5  = require("md5");

let ID;

function sendRawEmail(from, to, contents) {
  const outbound = require("./outbound");
  const plugin = this;

  ID =  md5(from + new Date().getTime());
  outbound.send_email(from, to, contents);

  return {
    id: ID,
    from,
    to,
    message: `Message queued as ${ID}`
  }
}

function sendMail(sendTo) {
  const outbound = require('./outbound');
  const plugin = this;

  const from = 'sender@test.com';

  const contents = [
    "From: " + from,
    "To: " + sendTo,
    "MIME-Version: 1.0",
    "Content-type: text/plain; charset=us-ascii",
    "Subject: Test message with VMTA!",
    "",
    "Some email body here",
    ""].join("\n");

  outbound.send_email(from, sendTo, contents);

  const id = md5(from + new Date().getTime());
  return { id, from, to: sendTo, message: `Message queued as ${id}` };
}

function registerPlugin() {
  const plugin = this;
  plugin.register_hook("delivered", "delivered");
  plugin.register_hook("bounce", "bounced");
  plugin.register_hook("deferred", "deferred");
}

function setupServer(next, Server) {

  const { app } = Server.http;
  const bodyParser = require("body-parser");
  app.use(bodyParser.json());

  const urlEncoded = bodyParser.urlencoded({ extended: true });

  app.get("/send/:email", (req, res) => {
    const { email } = req.params;
    res.json(sendMail(email));
  });

  app.post("/send-raw", urlEncoded, (req, res) => {
    const { from, to, contents } = req.body;
    res.json(sendRawEmail(from, to, contents));
  });

}

function writeStats(filename, next, hmail) {
  let content = new Date().toISOString().slice(0, 19).replace('T', ' ') + ",";
  content += hmail.todo.queue_time + ",";
  content +=  hmail.todo.rcpt_to[0].original +  "\n";

  this.loginfo(content);

  fs.appendFile("stats/" + filename, content, (err) => {
    if(!err) { this.loginfo("Added to " + filename) }
  });
}

function delivered(next, hmail, params) {
  this.loginfo("Message delivered!");
  writeStats.call(this, "delivered.csv", next, hmail);
  next();
}

function bounced(next, hmail, error) {
  this.loginfo("Message bounced!");
  writeStats.call(this, "bounced.csv", next, hmail);
  next();
}

function deferred(next, hmail, msg) {
  this.loginfo("Message deferred!");
  writeStats.call(this, "deffered.csv", next, hmail);
  next();
}

exports.register = registerPlugin;
exports.hook_init_http = setupServer;
exports.delivered = delivered;
exports.bounce = bounced;

On the same machine I'm running Python script that is calling send-raw and passing messages. However after 10K delivered messages Haraka is crashing with this message:

[CRIT] [-] [core] Error: Callback was already called.
[CRIT] [-] [core]     at /usr/local/lib/node_modules/Haraka/node_modules/async/dist/async.js:840:32
[CRIT] [-] [core]     at HMailItem.hmail.next_cb (/usr/local/lib/node_modules/Haraka/outbound.js:109:9)
[CRIT] [-] [core]     at /usr/local/lib/node_modules/Haraka/outbound.js:2236:15
[CRIT] [-] [core]     at FSReqWrap.oncomplete (fs.js:135:15)

I though this is related with my not-so-good logging for delivered, bounced, and deferred hooks but If I remove that part same thing happens.


Haraka

Stack Version
Haraka Haraka.js — Version: 2.8.13
Node v8.0.0
OS Ubuntu 16.04
openssl OpenSSL 1.0.2g 1 Mar 2016
baudehlo commented 7 years ago

This is a duplicate of #1954