Shodan crashes SMTP server

[Redsandro]

Certain Shodan (server search engine) incoming connections crash the app.

I'm not sure where to begin or where to report an issue. This seems like a good start.

mserve [2019-05-09 14:08:36] INFO  [#gcykk4jrmfnjq4no] Connection from border.census.shodan.io
mserve [2019-05-09 14:08:36] DEBUG [#gcykk4jrmfnjq4no] S: 220 924b8a533cda ESMTP
mserve [2019-05-09 14:08:39] DEBUG [#gcykk4jrmfnjq4no] C: EHLO QrpXbJxQgUsounK.org
mserve [2019-05-09 14:08:39] DEBUG [#gcykk4jrmfnjq4no] S: 250-924b8a533cda Nice to meet you, border.census.shodan.io
mserve [2019-05-09 14:08:39] DEBUG [#gcykk4jrmfnjq4no] 250-PIPELINING
mserve [2019-05-09 14:08:39] DEBUG [#gcykk4jrmfnjq4no] 250-8BITMIME
mserve [2019-05-09 14:08:39] DEBUG [#gcykk4jrmfnjq4no] 250-SMTPUTF8
mserve [2019-05-09 14:08:39] DEBUG [#gcykk4jrmfnjq4no] 250-SIZE 10485760
mserve [2019-05-09 14:08:39] DEBUG [#gcykk4jrmfnjq4no] 250 XFORWARD NAME ADDR PORT PROTO HELO IDENT SOURCE
mserve [2019-05-09 14:08:39] INFO  [#c3pznp2os2i5ku4v] Connection from border.census.shodan.io
mserve [2019-05-09 14:08:39] ERROR write EPROTO 140286581222280:error:140800FF:SSL routines:ssl3_accept:unknown state:../deps/openssl/openssl/ssl/s3_srvr.c:869:
mserve [2019-05-09 14:08:39] ERROR 
mserve 2019-05-09T14:08:39.984Z [api] error: Error write EPROTO 140286581222280:error:140800FF:SSL routines:ssl3_accept:unknown state:../deps/openssl/openssl/ssl/s3_srvr.c:869:
mserve [2019-05-09 14:08:39] DEBUG [#c3pznp2os2i5ku4v] S: 220 924b8a533cda ESMTP
mserve exited with code 139

Any thoughts?

[Redsandro]

And again

09:40:30 INFO  [#2dfb3imjyqh3oqrz] Connection from dojo.census.shodan.io
09:40:30 DEBUG [#2dfb3imjyqh3oqrz] S: 220 c4ecc22331e6 ESMTP
09:40:32 DEBUG [#2dfb3imjyqh3oqrz] C: EHLO 4lrjjWnIHzDds.com
09:40:32 DEBUG [#2dfb3imjyqh3oqrz] S: 250-c4ecc22331e6 Nice to meet you, dojo.census.shodan.io
09:40:32 DEBUG [#2dfb3imjyqh3oqrz] 250-PIPELINING
09:40:32 DEBUG [#2dfb3imjyqh3oqrz] 250-8BITMIME
09:40:32 DEBUG [#2dfb3imjyqh3oqrz] 250-SMTPUTF8
09:40:32 DEBUG [#2dfb3imjyqh3oqrz] 250-SIZE 10485760
09:40:32 DEBUG [#2dfb3imjyqh3oqrz] 250 XFORWARD NAME ADDR PORT PROTO HELO IDENT SOURCE
09:40:32 INFO  [#wv5xmdc7czgavji6] Connection from dojo.census.shodan.io
09:40:32 ERROR write EPROTO 139780310326152:error:140800FF:SSL routines:ssl3_accept:unknown state:../deps/openssl/openssl/ssl/s3_srvr.c:869:
09:40:32 ERROR 
09:40:32 [api] error: Error write EPROTO 139780310326152:error:140800FF:SSL routines:ssl3_accept:unknown state:../deps/openssl/openssl/ssl/s3_srvr.c:869:
09:40:32 DEBUG [#wv5xmdc7czgavji6] S: 220 c4ecc22331e6 ESMTP
api exited with code 139

This is the output with the option logger: true. The actual crashing #id is always preceded with a different id but also from shodan.io.

[andris9]

Do you have an error handler set for the server instance? Like this here?

[Redsandro]

Thank you @andris9.

Yes. The last error from smtp-server's logging: true is repeated.

SMTP-server:

ERROR write EPROTO 139780310326152:error:140800FF:SSL routines:ssl3_accept:unknown state:../deps/openssl/openssl/ssl/s3_srvr.c:869:

Error handler:

09:40:32 [api] error: Error write EPROTO 139780310326152:error:140800FF:SSL routines:ssl3_accept:unknown state:../deps/openssl/openssl/ssl/s3_srvr.c:869:

But I'm realizing I did the pretty useless thing:

server.on('error', err => {
    logger.error(`Error ${err.message}`)
})

...and assume you're interested in the stack trace. I will change err.message to err.stack and report back when this occurs next.

[Redsandro]

@andris9 I got hit with a different error which I think is unrelated

    server.on('error', err => {
        logger.error(err.stack)
    })

Error: 139867548191624:error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher:../deps/openssl/openssl/ssl/s3_srvr.c:1427:

That's it, the next line in the stack is empty. The reason I mentioned this is that there is no stack trace. Even though this is a different error in the same s3_srvr.c file provided by the smtp-mailer module. So changing error.message to error.stack won't lead to any new insights.

[Redsandro]

140392723741544:error:140760FC:SSL routines:SSL23_GET_CLIENT_HELLO:unknown protocol:../deps/openssl/openssl/ssl/s23_srvr.c:643:

This happens a lot too. There is no stack trace. Can I install this module with some kind of debugging mode that includes a stack trace?

[andris9]

Does the SMTP server crash on such errors or is this just something that gets logged as an error by the error handler?

[andris9]

This specific error means that the client tries to use incompatible TLS ciphers/settings. Normal behavior should be that the error is logged by error handler (if you choose to log it) and the connection to client is closed.

[Redsandro]

@andris9 there is one that crashes the SMTP server and that is this one:

Error write EPROTO 139780310326152:error:140800FF:SSL routines:ssl3_accept:unknown state:../deps/openssl/openssl/ssl/s3_srvr.c:869:

The others simply get logged by the error handler without crashing, and I would like to see more to see if the problems are related and understand how I can remedy this.

[andris9]

What log item is this: [api] error: this does not seem to be from smtp-server, what is that api prefix?

[Redsandro]

Apologies for the confusion. I'm using winston to log these errors to kibana, and winston prepends the label and "error:" because of the logger function:

format.printf(({ level, message, label = 'api', timestamp }) =>
    `${timestamp} [${label}] ${level}: ${message}`
)

[andris9]

Is this server behind a proxy? You have XFORWARD enabled.

09:40:32 ERROR write EPROTO line is from smtp-server error handler, I presume. But how this line gets triggered: 09:40:32 [api] error: Error write EPROTO ?

[andris9]

Does your error handler pass the error to some other function or do you have multiple error handlers set or do you have a uncaught errors handler that somehow catches it?

[Redsandro]

Is this server behind a proxy? You have XFORWARD enabled.

Yes this is true. The app is meant for deployment on docker swarm or kubernetes, so right now the app is launched as a docker container behind nginx-proxy.

However, I believe currently the email ports are mapped directly to the host, bypassing the nginx-proxy.

Here is the docker-compose part related to the api service (which has the smtp-server):

# Author: Redsandro (https://www.Redsandro.com/)
version: "3.5"

networks:
    proxy:
        external:
            name: proxy

volumes:
    conf.d:
    vhost.d:
    html:
    certs:

services:
    nginx:
        image: nginx
        container_name: nginx
        restart: always
        networks:
            - proxy
        ports:
            - 80:80
            - 443:443
        volumes:
            - conf.d:/etc/nginx/conf.d
            - vhost.d:/etc/nginx/vhost.d
            - html:/usr/share/nginx/html
            - certs:/etc/nginx/certs
    nginx-gen:
        image: jwilder/docker-gen
        container_name: nginx-gen
        command: -notify-sighup nginx -watch -wait 5s:30s /etc/docker-gen/templates/nginx.tmpl /etc/nginx/conf.d/default.conf
        restart: always
        networks:
            - proxy
        volumes:
            - conf.d:/etc/nginx/conf.d
            - vhost.d:/etc/nginx/vhost.d
            - html:/usr/share/nginx/html
            - certs:/etc/nginx/certs
            # Server template
            - ./nginx.tmpl.go:/etc/docker-gen/templates/nginx.tmpl:ro
            # Docker socket for detecting app reboot
            - /var/run/docker.sock:/tmp/docker.sock:ro

    nginx-letsencrypt:
        image: jrcs/letsencrypt-nginx-proxy-companion
        container_name: nginx-letsencrypt
        restart: unless-stopped
        volumes:
            - conf.d:/etc/nginx/conf.d
            - vhost.d:/etc/nginx/vhost.d
            - html:/usr/share/nginx/html
            - certs:/etc/nginx/certs
            # Docker socket for detecting app reboot
            - /var/run/docker.sock:/var/run/docker.sock:ro
        environment:
            NGINX_DOCKER_GEN_CONTAINER: nginx-gen
            NGINX_PROXY_CONTAINER: nginx

    api:
        image: example/cs-api:0.5.0
        container_name: cs-api
        restart: always
        networks:
            - proxy
        ports:
            - '25:25'
            - '465:465'
            - '587:587'
        volumes:
            - certs:/certs
        env_file:
            - api.env
        environment:
            TLS_KEY: /certs/cs.example.com.key
            TLS_CERT: /certs/cs.example.com.crt
            TLS_DHPARAM: /certs/cs.example.com.dhparam.pem
            VIRTUAL_HOST: cs.example.com
            VIRTUAL_PORT: 8080
            LETSENCRYPT_HOST: cs.example.com
            LETSENCRYPT_EMAIL: exampledev+letsencrypt@gmail.com

Perhaps this is the relevant part:

    api:
        ports:
            - '25:25'
            - '465:465'
            - '587:587'
        environment:
            TLS_KEY: /certs/cs.example.com.key
            TLS_CERT: /certs/cs.example.com.crt
            TLS_DHPARAM: /certs/cs.example.com.dhparam.pem

Does your error handler pass the error to some other function or do you have multiple error handlers set or do you have a uncaught errors handler that somehow catches it?

The error is not passed. It's this code that logs all the errors, but only that one specific error causes a crash.

    const server = new SMTPServer(opts)
    // ...
    server.on('error', err => {
        const {message, stack} = err
        logger.error({message, stack}) // winston
    })

[Redsandro]

Is it possible to attach the debug log from the SMTPServer option logger: true to any error thrown from the current invocation to which the debug log pertains?

It would be helpful to have these two together, especially when logging errors to an external service like kibana.

[andris9]

It would be best if you could minimize the code needed for the error to happen. There is no way I can reproduce the described setting. Best case would be to have a single javascript file to run as the server and single script as a client that crashes the server on connect.

[Redsandro]

@andris9 I completely understand. However I cannot reproduce this on a test domain, because there is not enough naughty traffic. This only happens on hour production server which handles a lot of emails, and is being probed and attacked from all sides. But I cannot replace the production application with a testcase. It would make a lot of people angry if the service disappears.

Is there anything else that we can do to capture the culprit?