Why is my use of hypnotoad crashing on Heroku?

852 Views Asked by At

I'm trying to get hypnotoad with a Mojolicious::Lite app running on Heroku with Perloku. There's something that doesn't happen when hypnotoad gets into its run loop that causes it to crash. I figure I'm missing something simple, but the Heroku docs haven't helped and I haven't been able to coax good error messages out of this.

I start with a very simple application so show some environment variables:

#!/usr/bin/env perl
# today
use Mojolicious::Lite;

get '/' => sub {
    my $c = shift;

    my $content = "Perl: $^X Pid: $$\n\n";
    foreach my $key ( keys %ENV ) {
        next unless $key =~ /Mojo|toad/i;
        $content .= "$key $ENV{$key}\n";
        }

    $c->stash( content => $content );

    $c->render('index');
    };

app->start;

__DATA__

@@ index.html.ep
% layout 'default';
% title 'Welcome';
<p>Welcome to the Mojolicious real-time web framework!</p>

<pre>
<%= $content %>
</pre>

@@ layouts/default.html.ep
<!DOCTYPE html>
<html>
  <head><title><%= title %></title></head>
  <body><%= content %></body>
</html>

When I run this locally, I have no problem. I see from the environment variables that my program is run under hypnotoad:

Welcome to the Mojolicious real-time web framework!

Perl: /Users/brian/Dropbox/bin/perls/perl5.20.0 Pid: 40006

HYPNOTOAD_PID 39981
MOJO_HELP 
HYPNOTOAD_TEST 
HYPNOTOAD_EXE /Users/brian/bin/perls/hypnotoad5.20.0
MOJO_REUSE 0.0.0.0:8080:6
HYPNOTOAD_REV 3
HYPNOTOAD_APP /Users/brian/Desktop/toady.d/toady
MOJO_MODE production
MOJO_HOME
HYPNOTOAD_STOP 
HYPNOTOAD_FOREGROUND

Now, I deploy this with Mojolicious::Command::deploy::heroku:

% toady deploy heroku --create

This is running at https://frozen-brushlands-4002.herokuapp.com, using the default Perloku file:

#!/bin/sh
./toady daemon --listen http://*:$PORT --mode production

This isn't running hypnotoad though, despite some references I've seen that says that's what I should get. The application works, though:

Welcome to the Mojolicious real-time web framework!

Perl: /app/vendor/perl/bin/perl Pid: 3

MOJO_REUSE 0.0.0.0:12270:4
MOJO_HOME 
MOJO_HELP 
MOJO_MODE production
MOJO_EXE ./toady

I figured I could just change the Perloku file to start hypnotoad:

#!/bin/sh
/app/vendor/perl/bin/perl /app/vendor/perl-deps/bin/hypnotoad toady

hypnotoad starts and almost immediately shuts down with no other log messages:

% heroku logs --app ...
2015-01-04T09:23:36.516864+00:00 heroku[web.1]: Starting process with command `./Perloku`
2015-01-04T09:23:38.321628+00:00 heroku[web.1]: State changed from starting to crashed

I can change the invocation to use the -t to test the app to see if :

#!/bin/sh
/app/vendor/perl/bin/perl /app/vendor/perl-deps/bin/hypnotoad -t toady

That works and I get the "Everything looks good!" message, so hypnotoad is running:

2015-01-04T09:36:36.955680+00:00 heroku[web.1]: Starting process with command `./Perloku`
2015-01-04T09:36:38.340717+00:00 app[web.1]: Everything looks good!
2015-01-04T09:36:39.085887+00:00 heroku[web.1]: State changed from starting to crashed

I turn on Mojo debug logging, but I don't see additional output other than my own statements.

#!/usr/bin/env perl
use Mojolicious::Lite;

$|++;

my $log = app->log;

$log->level( 'debug' );

$log->debug( "INC: @INC" );

get '/' => sub {
    ...;
    };

$log->debug( "Right before start" );
my $app = app->start;
$log->debug( "Right after start" );

$app; # must return application object

I tried other things, such as making it load a module I know is not there and I get the expected "Could not find" error in the logs.

Running from the shell in heroku (heroku run bash) was not illuminating. The output of mojo version is the same as on my local machine:

$ perl vendor/perl-deps/bin/mojo version
CORE
  Perl        (v5.16.2, linux)
  Mojolicious (5.71, Tiger Face)

OPTIONAL
  EV 4.0+                 (n/a)
  IO::Socket::Socks 0.64+ (n/a)
  IO::Socket::SSL 1.84+   (n/a)
  Net::DNS::Native 0.15+  (n/a)

You might want to update your Mojolicious to 5.72.

I figure there's something really simple that I'm missing, but at the same time, none of this is architected for easy debugging.


Oleg gets a little closer, but there are still problems. I had tried the foreground option before and run into the same problems but failed to mention it.

If I start hypnotoad in the foreground, it tries to bind to an address. It can't bind to port 80 (or 443) and crashes, and it can listen to 127.0.0.1: almost, but it looks like it fails to completely listen:

2015-01-13T11:47:54+00:00 heroku[slug-compiler]: Slug compilation started
2015-01-13T11:48:32+00:00 heroku[slug-compiler]: Slug compilation finished
2015-01-13T11:48:32.735095+00:
00 heroku[api]: Deploy dcab778 by ...
2015-01-13T11:48:32.735095+00:00 heroku[api]: Release v31 created by ...
2015-01-13T11:48:32.969489+00:00 heroku[web.1]: State changed from crashed to starting
2015-01-13T11:48:34.909134+00:00 heroku[web.1]: Starting process with command `./Perloku`
2015-01-13T11:48:36.045985+00:00 app[web.1]: Can't create listen socket: Permission denied at /app/vendor/perl-deps/lib/perl5/Mojo/IOLoop.pm line 120.
2015-01-13T11:48:36.920004+00:00 heroku[web.1]: Process exited with status 13
2015-01-13T11:48:36.932014+00:00 heroku[web.1]: State changed from starting to crashed

Here's with an unprivileged port:

2015-01-13T11:39:10+00:00 heroku[slug-compiler]: Slug compilation started
2015-01-13T11:39:44+00:00 heroku[slug-compiler]: Slug compilation finished
2015-01-13T11:39:44.519679+00:00 heroku[api]: Deploy bbd1f68 by ...
2015-01-13T11:39:44.519679+00:00 heroku[api]: Release v29 created by ...
2015-01-13T11:39:44.811111+00:00 heroku[web.1]: State changed from crashed to starting
2015-01-13T11:39:47.382298+00:00 heroku[web.1]: Starting process with command `./Perloku`
2015-01-13T11:39:48.454706+00:00 app[web.1]: [Tue Jan 13 11:39:48 2015] [info] Listening at "http://*:8000".
2015-01-13T11:39:48.454733+00:00 app[web.1]: Server available at http://127.0.0.1:8000.
2015-01-13T11:39:48.454803+00:00 app[web.1]: [Tue Jan 13 11:39:48 2015] [info] Manager 3 started.
2015-01-13T11:39:48.480084+00:00 app[web.1]: [Tue Jan 13 11:39:48 2015] [info] Creating process id file "/app/hypnotoad.pid".
2015-01-13T11:40:47.703110+00:00 heroku[web.1]: Stopping process with SIGKILL
2015-01-13T11:40:47.702867+00:00 heroku[web.1]: Error R10 (Boot timeout) -> Web process failed to bind to $PORT within 60 seconds of launch
2015-01-13T11:40:48.524470+00:00 heroku[web.1]: Process exited with status 137
2015-01-13T11:40:48.534002+00:00 heroku[web.1]: State changed from starting to crashed
3

There are 3 best solutions below

2
On BEST ANSWER

Oleg answers the question, but there are some pieces missing in the assumptions.

First, create a new heroku app and remember the name of the app:

$ heroku create
 Creating vast-spire-6174... done, stack is cedar-14
 https://vast-spire-6174.herokuapp.com/ | https://git.heroku.com/vast-spire-6174.git

Next, add the Perloku build pack:

$ heroku config:add BUILDPACK_URL=https://github.com/judofyr/perloku.git

Create the git repo and setup on Heroku:

$ mkdir testapp
$ cd testapp
$ git init
$ heroku git:remote -a vast-spire-6174

To make everything work, you need a Perloku file to start hypnotoad in the foreground. You have to specify perl explicity because the shebang line in hypnotoad refers to the temp location of perl when it was built and where it no longer is. Change myapp.pl to whatever you named your application.

#!/bin/sh
/app/vendor/perl/bin/perl /app/vendor/perl-deps/bin/hypnotoad -f myapp.pl

To get everything installed, you use a standard Makefile.PL. Specify Mojolicious as one of the prerequisites:

use strict;
use warnings;

use ExtUtils::MakeMaker;

WriteMakefile(
  VERSION   => '0.01',
  PREREQ_PM => {'Mojolicious' => '5.72'},
  test      => {TESTS => 't/*.t'}
);

Finally, the app itself, which you can create with mojo (which calls is myapp.ppl)

$ mojo generate lite_app

Here's the generated source:

#!/usr/bin/env perl
use Mojolicious::Lite;

# Documentation browser under "/perldoc"
plugin 'PODRenderer';

get '/' => sub {
  my $c = shift;
  $c->render('index');
};

app->start;
__DATA__

@@ index.html.ep
% layout 'default';
% title 'Welcome';
Welcome to the Mojolicious real-time web framework!

@@ layouts/default.html.ep
<!DOCTYPE html>
<html>
  <head><title><%= title %></title></head>
  <body><%= content %></body>
</html>

You have to modify the basic program since hypnotoad needs a bit of configuration (where the default server does not):

#!/usr/bin/env perl
use Mojolicious::Lite;

# Documentation browser under "/perldoc"
plugin 'PODRenderer';

plugin Config => {
    default => {
        hypnotoad => {
            listen => ["http://*:$ENV{PORT}"]
            }
        }
    };

get '/' => sub {
  my $c = shift;
  $c->render('index');
};

app->start;
__DATA__

@@ index.html.ep
% layout 'default';
% title 'Welcome';
Welcome to the Mojolicious real-time web framework!

@@ layouts/default.html.ep
<!DOCTYPE html>
<html>
  <head><title><%= title %></title></head>
  <body><%= content %></body>
</html>

Once you have all the files, commit them, and push to the heroku branch.

$ git add .
$ git commit -am "make it better"
$ git push heroku master

When you push, a hook will start up everything.

Counting objects: 7, done.
Delta compression using up to 4 threads.
Compressing objects: 100% (7/7), done.
Writing objects: 100% (7/7), 1.14 KiB | 0 bytes/s, done.
Total 7 (delta 0), reused 0 (delta 0)
remote: Compressing source files... done.
remote: Building source:
remote:
remote: -----> Fetching custom git buildpack... done
remote: -----> Perloku app detected
remote: -----> Vendoring Perl
remote:        Using Perl 5.18.1
remote: -----> Installing dependencies
remote:        --> Working on /tmp/build_a73f24f0619fa2ab299586098c5e8daf
remote:        Configuring /tmp/build_a73f24f0619fa2ab299586098c5e8daf ... OK
remote:        ==> Found dependencies: Mojolicious
remote:        --> Working on Mojolicious
remote:        Fetching http://www.cpan.org/authors/id/S/SR/SRI/Mojolicious-5.72.tar.gz ... OK
remote:        Configuring Mojolicious-5.72 ... OK
remote:        ==> Found dependencies: IO::Socket::IP
remote:        --> Working on IO::Socket::IP
remote:        Fetching http://www.cpan.org/authors/id/P/PE/PEVANS/IO-Socket-IP-0.36.tar.gz ... OK
remote:        Configuring IO-Socket-IP-0.36 ... OK
remote:        Building IO-Socket-IP-0.36 ... OK
remote:        Successfully installed IO-Socket-IP-0.36
remote:        Building Mojolicious-5.72 ... OK
remote:        Successfully installed Mojolicious-5.72
remote:        <== Installed dependencies for /tmp/build_a73f24f0619fa2ab299586098c5e8daf. Finishing.
remote:        2 distributions installed
remote:        Dependencies installed
remote: -----> Discovering process types
remote:        Procfile declares types   -> (none)
remote:        Default types for Perloku -> web
remote:
remote: -----> Compressing... done, 14.1MB
remote: -----> Launching... done, v5
remote:        https://vast-spire-6174.herokuapp.com/ deployed to Heroku
remote:
remote: Verifying deploy... done.
To https://git.heroku.com/vast-spire-6174.git
 * [new branch]      master -> master

The URL of your application shows up toward the end of the output.

Why this was working for me before I don't know. I was letting a mojo command deploy for me, so there could be something to investigate there. However, it's a bit easier to commit and push without the intermediary.

2
On

After some testing I found a way to run hypnotoad on heroku

1. Perloku content should looks like this

#!/bin/sh
perl /app/vendor/perl-deps/bin/hypnotoad -f mojocrashtest

Description

First of all we need to explicity call perl. Because

heroku run bash
head /app/vendor/perl-deps/bin/hypnotoad

shows

#!/tmp/perl/perls/perl-5.18.1/bin/perl

eval 'exec /tmp/perl/perls/perl-5.18.1/bin/perl  -S $0 ${1+"$@"}'
    if 0; # not running under some shell

where /tmp/perl/perls/perl-5.18.1/bin/perl doesn't exists. So, /app/vendor/perl-deps/bin/hypnotoad will not start, but perl /app/vendor/perl-deps/bin/hypnotoad will be ok.

Then we need key -f for hypnotoad as @moritz guessed. Otherwise heroku will think that your app finished unexpectedly.

2. You should start hypnotoad on port $ENV{PORT}

For Mojolicious::Lite you just need to write something like this at the top of your app:

plugin Config => {default => {hypnotoad => {listen => ["http://*:$ENV{PORT}"]}}};

For full app you can do it inside the startup handler.

3. heroku open


And this is a full code of Mojolicious::Lite application

#!/usr/bin/env perl
# today
use Mojolicious::Lite;

plugin Config => {default => {hypnotoad => {listen => ["http://*:$ENV{PORT}"]}}};

get '/' => sub {
    my $c = shift;

    my $content = "Perl: $^X Pid: $$\n\n";
    foreach my $key ( keys %ENV ) {
        next unless $key =~ /Mojo|toad/i;
        $content .= "$key $ENV{$key}\n";
        }

    $c->stash( content => $content );

    $c->render('index');
    };

app->start;

__DATA__

@@ index.html.ep
% layout 'default';
% title 'Welcome';
<p>Welcome to the Mojolicious real-time web framework!</p>

<pre>
<%= $content %>
</pre>

@@ layouts/default.html.ep
<!DOCTYPE html>
<html>
  <head><title><%= title %></title></head>
  <body><%= content %></body>
</html>

heroku logs

2015-01-13T12:08:04.843204+00:00 heroku[web.1]: Starting process with command `./Perloku`
2015-01-13T12:08:06.019070+00:00 app[web.1]: Server available at http://127.0.0.1:13533.
2015-01-13T12:08:06.018899+00:00 app[web.1]: [Tue Jan 13 12:08:06 2015] [info] Listening at "http://*:13533".
2015-01-13T12:08:06.019035+00:00 app[web.1]: [Tue Jan 13 12:08:06 2015] [info] Manager 3 started.
2015-01-13T12:08:06.055437+00:00 app[web.1]: [Tue Jan 13 12:08:06 2015] [info] Creating process id file "/app/hypnotoad.pid".
2015-01-13T12:08:06.412283+00:00 heroku[web.1]: State changed from starting to up
2015-01-13T12:08:08.040072+00:00 heroku[router]: at=info method=GET path="/" host=floating-temple-3676.herokuapp.com request_id=e9f9bb4d-f71f-4b4c-a129-70faf044c38b fwd=194" dyno=web.1 connect=3ms service=34ms status=200 bytes=586
2015-01-13T12:08:08.029819+00:00 app[web.1]: Use of uninitialized value in concatenation (.) or string at /app/mojocrashtest line 13, <DATA> line 39.
2015-01-13T12:08:08.029836+00:00 app[web.1]: Use of uninitialized value in concatenation (.) or string at /app/mojocrashtest line 13, <DATA> line 39.
2015-01-13T12:08:08.029839+00:00 app[web.1]: Use of uninitialized value in concatenation (.) or string at /app/mojocrashtest line 13, <DATA> line 39.
2015-01-13T12:08:08.029842+00:00 app[web.1]: Use of uninitialized value in concatenation (.) or string at /app/mojocrashtest line 13, <DATA> line 39.

URL for my app: http://floating-temple-3676.herokuapp.com/
BTW, I didn't use mojo deploy, just git

2
On

This is really just a wild guess, but maybe the heroku infrastructure doesn't expect the runner to terminate? If so, you could try to start hypnotoad with --foreground or -f.

Also, you could try to do some logging from inside the application to see if it ever runs it at all.