Cowboy 2 vs Zotonic vs XProf

[ddeboer]

Currently available in branch cowboy_2.0. See https://github.com/Appliscale/xprof/issues/73#issuecomment-322072437.

It compiles and xprof:start() works, but I’m getting some JavaScript errors:

[gomoripeti]

This looks like the static assets are loaded successfully into the browser but all REST API calls fail. As I cannot reproduce it (with make dev in xprof repo) could you check the Network tab in the browser and erlang/lager logs if they contain some more info about the failures?

(I pushed a small fix to the cowboy_2.0 branch but this issue looks more serious)

[gomoripeti]

During a common debugging session with @ddeboer we found that the problem (REST API always returns 204) only occurs when zotonic is started before xprof. If xprof is started before zotonic, they both work fine. Zotonic uses some custom cowboy middlewares and we suspect that maybe that affects the endpoint of zotonic, but it is not clear, why.

[gomoripeti]

I'd like to repurpose this ticket as an xprof vs zotonic bug report, and hande cowboy 2.0 feature itself here https://github.com/Appliscale/xprof/issues/99

[gomoripeti]

I updated the cowboy_2.0 branch to depend on published 2.0 cowboy hex package (and also merged latest xprof 1.3.0 tag)

@ddeboer could you try if the issue still persists with latest cowboy, if your time permits?

[kenny-evitt]

I tried using the cowboy_2.0 branch but Mix failed to install the package:

$ mix deps.get
...
* Getting xprof (https://github.com/appliscale/xprof.git)
remote: Enumerating objects: 107, done.        
remote: Counting objects: 100% (107/107), done.        
remote: Compressing objects: 100% (71/71), done.        
remote: Total 5209 (delta 40), reused 87 (delta 35), pack-reused 5102        
Receiving objects: 100% (5209/5209), 11.58 MiB | 13.04 MiB/s, done.
Resolving deltas: 100% (3263/3263), done.
** (Hex.Version.InvalidRequirementError) invalid requirement: "2.0"
    (hex) lib/hex/version.ex:134: Hex.Version.parse_requirement!/2
    (hex) lib/hex/version.ex:52: anonymous fn/3 in Hex.Version.match?/3
    (hex) lib/hex/version.ex:144: Hex.Version.cache/2
    (hex) lib/hex/remote_converger.ex:532: anonymous fn/2 in Hex.RemoteConverger.unlock_deps/2
    (elixir) lib/enum.ex:2934: Enum.filter_list/2
    (elixir) lib/enum.ex:2935: Enum.filter_list/2
    (hex) lib/hex/remote_converger.ex:526: Hex.RemoteConverger.unlock_deps/2
    (hex) lib/hex/remote_converger.ex:515: Hex.RemoteConverger.prepare_locked/3

I was able to install it after updating the Cowboy version in rebar.config:

• WIP: Fix (and update) Cowboy version · kenny-evitt/xprof@21bf9ea

[I used version 2.6.3, which is what my app is using, but 2.8.0 is the latest.]

I get a compile error for jsone tho when I try to run (compile) my app:

$ iex -S mix
Erlang/OTP 21 [erts-10.2.2] [source] [64-bit] [smp:4:4] [ds:4:4:10] [async-threads:1] [hipe]

===> Compiling jsone
===> Compiling src/jsone.erl failed
src/jsone.erl:261: erlang:get_stacktrace/0: deprecated; use the new try/catch syntax for retrieving the stack backtrace
src/jsone.erl:310: erlang:get_stacktrace/0: deprecated; use the new try/catch syntax for retrieving the stack backtrace

** (Mix) Could not compile dependency :jsone, "/Users/kenny/.asdf/installs/elixir/1.8.0/.mix/rebar3 bare compile --paths "/Users/kenny/@code/my_app/_build/dev/lib/*/ebin"" command failed. You can recompile this dependency with "mix deps.compile jsone", update it with "mix deps.update jsone" or clean it with "mix deps.clean jsone"

I'm on Erlang/OTP version 21.2.3.

[kenny-evitt]

Newer versions of jsone support Erlang/OTP 21:

• Cannot build on Erlang R21 · Issue #36 · sile/jsone

[kenny-evitt]

Updating jsone to the latest version (1.5.2) fixed the compile error.

I did see some warnings for another package tho:

...
===> Compiling customized_hdr_histogram
cc -O3 -std=c99 -arch x86_64 -Wall -Wmissing-prototypes -fPIC -I /Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/ -I /Users/kenny/.asdf/installs/erlang/21.2.3/lib/erl_interface-3.10.4/include  -c -o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram.o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram.c
cc -O3 -std=c99 -arch x86_64 -Wall -Wmissing-prototypes -fPIC -I /Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/ -I /Users/kenny/.asdf/installs/erlang/21.2.3/lib/erl_interface-3.10.4/include  -c -o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:216:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[0], &highest_trackable_value) ||
                                      ^~~~~~~~~~~~~~~~~~~~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:299:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[1], &value))
                                      ^~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:327:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[1], &value) ||
                                      ^~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:328:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[2], &expected_interval))
                                      ^~~~~~~~~~~~~~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:356:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[1], &value) ||
                                      ^~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:357:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[2], &count))
                                      ^~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:597:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[1], &a) ||
                                      ^~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:598:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[2], &b))
                                      ^~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:622:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[1], &value))
                                      ^~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
/Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.c:648:39: warning: incompatible pointer types passing 'int64_t *' (aka 'long long *') to parameter of type 'long *' [-Wincompatible-pointer-types]
        !enif_get_int64(env, argv[1], &value))
                                      ^~~~~~
/Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/erl_nif_api_funcs.h:104:79: note: passing argument to parameter 'ip' here
ERL_NIF_API_FUNC_DECL(int,enif_get_long,(ErlNifEnv*, ERL_NIF_TERM term, long* ip));
                                                                              ^
10 warnings generated.
cc -O3 -std=c99 -arch x86_64 -Wall -Wmissing-prototypes -fPIC -I /Users/kenny/.asdf/installs/erlang/21.2.3/erts-10.2.2/include/ -I /Users/kenny/.asdf/installs/erlang/21.2.3/lib/erl_interface-3.10.4/include  -c -o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_log.o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_log.c
cc /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram.o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_nif.o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/hdr_histogram_log.o -arch x86_64 -flat_namespace -undefined suppress -shared -L /Users/kenny/.asdf/installs/erlang/21.2.3/lib/erl_interface-3.10.4/lib -lerl_interface -lei -o /Users/kenny/@code/my_app/deps/customized_hdr_histogram/c_src/../priv/hdr_histogram_nif.so

[kenny-evitt]

I got xprof running just fine after updating the two deps.

I'm guessing I might need to ensure that lager starts when my app does:

17:33:58.109 initial_call=:lager_handler_watcher.init/1 function=crash_report/4 module=proc_lib line=508 file=proc_lib.erl pid=<0.458.0> [error] Process #PID<0.458.0> terminating
** (exit) no process: the process is not alive or there's no process currently associated with the given name, possibly because its application isn't started
    (stdlib) gen.erl:228: :gen.do_for_proc/2
    (stdlib) gen_event.erl:239: :gen_event.rpc/2
    (lager) /Users/kenny/@code/my_app/deps/lager/src/lager_handler_watcher.erl:117: :lager_handler_watcher.install_handler2/3
    (lager) /Users/kenny/@code/my_app/deps/lager/src/lager_handler_watcher.erl:51: :lager_handler_watcher.init/1
    (stdlib) gen_server.erl:374: :gen_server.init_it/2
    (stdlib) gen_server.erl:342: :gen_server.init_it/6
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Initial Call: :lager_handler_watcher.init/1
Ancestors: [:lager_handler_watcher_sup, :lager_sup, #PID<0.443.0>]
Message Queue Length: 0
Messages: []
Links: [#PID<0.446.0>]
Dictionary: []
Trapping Exits: false
Status: :running
Heap Size: 987
Stack Size: 27
Reductions: 252

Or is lager not necessary?

[gomoripeti]

hi @kenny-evitt thanks for trying xprof and extra thanks for going this far to make it work.

The cowboy_2.0 branch is very old. It would be best to try either the tag 2.0.0-rc.4 (also hex package) or the release_2.0 branch. I did some dependency version bumps there, exactly for the libs you found.

• Also switched customized_hdr_histogram to a newer version of upstream hdr_histogram. But if you still have issue compiling that, there is XPROF_ERL_HIST OS env var which you can set at compile time to use an Erlang implementation instead (see https://github.com/Appliscale/xprof/tree/release_2.0#compile-time-configuration)
• xprof indeed depends on lager, but if you use Application:ensure_all_started(:xprof) it might help. But it might be a conflict with the new OTP logger in OTP 21 and a too old version of lager that the cowboy_2.0 branch tries to use.

Thanks again and let me know how either tag 2.0.0-rc.4 or branch release_2.0 works for you.

[kenny-evitt]

@gomoripeti Thanks!

I'm actually, currently, looking for a tracing tool with stacktraces, but I may come back to xprof a bit later – thanks for it by-the-way!