(FunctionClauseError) no function clause matching in anonymous fn/1 in Socket.arguments/1 when creating Producer

[malcolmrebughini]

As soon as this is called:

NSQ.Producer.Supervisor.start_link(
      "tracks",
      %NSQ.Config{
        nsqds: ["127.0.0.1:4150", "127.0.0.1:4151"]
      }
    )

The following error is thrown:

** (FunctionClauseError) no function clause matching in anonymous fn/1 in Socket.arguments/1
    (socket) lib/socket.ex:170: anonymous fn({:active, false}) in Socket.arguments/1
    (elixir) lib/enum.ex:1003: Enum.flat_map_list/2
    (elixir) lib/enum.ex:1004: Enum.flat_map_list/2
    (socket) lib/socket/tcp.ex:285: Socket.TCP.arguments/1
    (socket) lib/socket/tcp.ex:108: Socket.TCP.connect/3
    (elixir_nsq) lib/nsq/connection/initializer.ex:24: NSQ.Connection.Initializer.connect/1
    (elixir_nsq) lib/nsq/connection.ex:99: NSQ.Connection.init/1
    (stdlib) gen_server.erl:365: :gen_server.init_it/2
    (stdlib) gen_server.erl:333: :gen_server.init_it/6
    (stdlib) proc_lib.erl:247: :proc_lib.init_p_do_apply/3
Last message: {:EXIT, #PID<0.1202.0>, {:function_clause, [{Socket, :"-arguments/1-fun-2-", [active: false], [file: 'lib/socket.ex', line: 170]}, {Enum, :flat_map_list, 2, [file: 'lib/enum.ex', line: 1003]}, {Enum, :flat_map_list, 2, [file: 'lib/enum.ex', line: 1004]}, {Socket.TCP, :arguments, 1, [file: 'lib/socket/tcp.ex', line: 285]}, {Socket.TCP, :connect, 3, [file: 'lib/socket/tcp.ex', line: 108]}, {NSQ.Connection.Initializer, :connect, 1, [file: 'lib/nsq/connection/initializer.ex', line: 24]}, {NSQ.Connection, :init, 1, [file: 'lib/nsq/connection.ex', line: 99]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}
State: {:state, {#PID<0.1205.0>, NSQ.Message.Supervisor}, :one_for_one, [], :undefined, 3, 5, [], 0, NSQ.Message.Supervisor, :ok}
[error] GenServer #PID<0.1199.0> terminating
** (MatchError) no match of right hand side value: {:error, {{:EXIT, {{:badmatch, {:error, {:function_clause, [{Socket, :"-arguments/1-fun-2-", [active: false], [file: 'lib/socket.ex', line: 170]}, {Enum, :flat_map_list, 2, [file: 'lib/enum.ex', line: 1003]}, {Enum, :flat_map_list, 2, [file: 'lib/enum.ex', line: 1004]}, {Socket.TCP, :arguments, 1, [file: 'lib/socket/tcp.ex', line: 285]}, {Socket.TCP, :connect, 3, [file: 'lib/socket/tcp.ex', line: 108]}, {NSQ.Connection.Initializer, :connect, 1, [file: 'lib/nsq/connection/initializer.ex', line: 24]}, {NSQ.Connection, :init, 1, [file: 'lib/nsq/connection.ex', line: 99]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}}, [{NSQ.Connection, :start_link, 8, [file: 'lib/nsq/connection.ex', line: 82]}, {:supervisor, :do_start_child, 2, [file: 'supervisor.erl', line: 365]}, {:supervisor, :handle_start_child, 2, [file: 'supervisor.erl', line: 724]}, {:supervisor, :handle_call, 3, [file: 'supervisor.erl', line: 422]}, {:gen_server, :try_handle_call, 4, [file: 'gen_server.erl', line: 636]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 665]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}, {:child, :undefined, "parent:#PID<0.1198.0>:conn:127.0.0.1:4150", {NSQ.Connection, :start_link, [#PID<0.1198.0>, {"127.0.0.1", 4150}, %NSQ.Config{client_id: nil, max_backoff_duration: 120000, max_in_flight: 2500, tls_key: nil, user_agent: nil, write_timeout: 1000, backoff_multiplier: 1000, nsqlookupds: [], hostname: nil, tls_min_version: nil, max_reconnect_attempts: 30, msg_timeout: 60000, snappy: false, tls_cert: nil, output_buffer_size: 16384, read_timeout: 60000, heartbeat_interval: 30000, lookupd_poll_interval: 60000, auth_secret: "", deflate_level: 6, tls_insecure_skip_verify: false, dial_timeout: 1000, rdy_redistribute_interval: 5000, rdy_retry_delay: 5000, low_rdy_idle_timeout: 10000, nsqds: [{"127.0.0.1", 4150}, {"127.0.0.1", 4151}], max_attempts: 5, deflate: false, lookupd_poll_jitter: 0.3, output_buffer_timeout: 250, max_requeue_delay: 900000, backoff_strategy: :exponential, sample_rate: 0, event_manager: nil, tls_v1: false, message_handler: nil}, "tracks", nil, #PID<0.1200.0>, #PID<0.1201.0>]}, :temporary, 5000, :worker, [NSQ.Connection]}}}
    (elixir_nsq) lib/nsq/producer.ex:183: anonymous fn/3 in NSQ.Producer.connect_to_nsqds/3
    (elixir) lib/enum.ex:1270: Enum."-map/2-lists^map/1-0-"/2
    (elixir_nsq) lib/nsq/producer.ex:182: NSQ.Producer.connect_to_nsqds/3
    (elixir_nsq) lib/nsq/producer.ex:105: NSQ.Producer.init/1
    (stdlib) gen_server.erl:365: :gen_server.init_it/2
    (stdlib) gen_server.erl:333: :gen_server.init_it/6
    (stdlib) proc_lib.erl:247: :proc_lib.init_p_do_apply/3
Last message: {:EXIT, #PID<0.1198.0>, {{:badmatch, {:error, {{:EXIT, {{:badmatch, {:error, {:function_clause, [{Socket, :"-arguments/1-fun-2-", [active: false], [file: 'lib/socket.ex', line: 170]}, {Enum, :flat_map_list, 2, [file: 'lib/enum.ex', line: 1003]}, {Enum, :flat_map_list, 2, [file: 'lib/enum.ex', line: 1004]}, {Socket.TCP, :arguments, 1, [file: 'lib/socket/tcp.ex', line: 285]}, {Socket.TCP, :connect, 3, [file: 'lib/socket/tcp.ex', line: 108]}, {NSQ.Connection.Initializer, :connect, 1, [file: 'lib/nsq/connection/initializer.ex', line: 24]}, {NSQ.Connection, :init, 1, [file: 'lib/nsq/connection.ex', line: 99]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}}, [{NSQ.Connection, :start_link, 8, [file: 'lib/nsq/connection.ex', line: 82]}, {:supervisor, :do_start_child, 2, [file: 'supervisor.erl', line: 365]}, {:supervisor, :handle_start_child, 2, [file: 'supervisor.erl', line: 724]}, {:supervisor, :handle_call, 3, [file: 'supervisor.erl', line: 422]}, {:gen_server, :try_handle_call, 4, [file: 'gen_server.erl', line: 636]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 665]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}, {:child, :undefined, "parent:#PID<0.1198.0>:conn:127.0.0.1:4150", {NSQ.Connection, :start_link, [#PID<0.1198.0>, {"127.0.0.1", 4150}, %NSQ.Config{client_id: nil, max_backoff_duration: 120000, max_in_flight: 2500, tls_key: nil, user_agent: nil, write_timeout: 1000, backoff_multiplier: 1000, nsqlookupds: [], hostname: nil, tls_min_version: nil, max_reconnect_attempts: 30, msg_timeout: 60000, snappy: false, tls_cert: nil, output_buffer_size: 16384, read_timeout: 60000, heartbeat_interval: 30000, lookupd_poll_interval: 60000, auth_secret: "", deflate_level: 6, tls_insecure_skip_verify: false, dial_timeout: 1000, rdy_redistribute_interval: 5000, rdy_retry_delay: 5000, low_rdy_idle_timeout: 10000, nsqds: [{"127.0.0.1", 4150}, {"127.0.0.1", 4151}], max_attempts: 5, deflate: false, lookupd_poll_jitter: 0.3, output_buffer_timeout: 250, max_requeue_delay: 900000, backoff_strategy: :exponential, sample_rate: 0, event_manager: nil, tls_v1: false, ...}, "tracks", nil, #PID<0.1200.0>, #PID<0.1201.0>]}, :temporary, 5000, :worker, [NSQ.Connection]}}}}, [{NSQ.Producer, :"-connect_to_nsqds/3-fun-0-", 3, [file: 'lib/nsq/producer.ex', line: 183]}, {Enum, :"-map/2-lists^map/1-0-", 2, [file: 'lib/enum.ex', line: 1270]}, {NSQ.Producer, :connect_to_nsqds, 3, [file: 'lib/nsq/producer.ex', line: 182]}, {NSQ.Producer, :init, 1, [file: 'lib/nsq/producer.ex', line: 105]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}
State: {:state, {#PID<0.1199.0>, NSQ.Connection.Supervisor}, :one_for_one, [], :undefined, 3, 5, [], 0, NSQ.Connection.Supervisor, :ok}

Running Elixir 1.5.2, Erlang/OTP 20.

{:elixir_nsq, "~> 1.0.3"},

[MaxPower15]

Hey there, can you try using github: "wistia/elixir_nsq", tag: "HEAD" instead of "~> 1.0.3" as your version? This strikes me as the same bug that was fixed in #6, but I still haven't got around to updating the package in hex unfortunately.

[malcolmrebughini]

@MaxPower15 First of all, thank you for the quick response.

Did that, now the error changed and I see something in the nsq logs.

[debug] (#PID<0.969.0>) identifying...
[debug] Not compressing or decompressing data
[debug] Not compressing or decompressing data
[debug] (#PID<0.974.0>) sending magic v2...
[debug] (#PID<0.974.0>) identifying...
[error] GenServer #PID<0.977.0> terminating
** (MatchError) no match of right hand side value: {:error, "socket closed"}
    (elixir_nsq) lib/nsq/connection/buffer.ex:88: NSQ.Connection.Buffer.recv!/2
    (elixir_nsq) lib/nsq/connection/initializer.ex:201: NSQ.Connection.Initializer.recv_nsq_response/1
    (elixir_nsq) lib/nsq/connection/initializer.ex:90: NSQ.Connection.Initializer.identify/1
    (elixir_nsq) lib/nsq/connection/initializer.ex:63: NSQ.Connection.Initializer.do_handshake/1
    (elixir_nsq) lib/nsq/connection/initializer.ex:73: NSQ.Connection.Initializer.do_handshake!/1
    (elixir_nsq) lib/nsq/connection/initializer.ex:30: NSQ.Connection.Initializer.connect/1
    (elixir_nsq) lib/nsq/connection.ex:99: NSQ.Connection.init/1
    (stdlib) gen_server.erl:365: :gen_server.init_it/2
    (stdlib) gen_server.erl:333: :gen_server.init_it/6
    (stdlib) proc_lib.erl:247: :proc_lib.init_p_do_apply/3
Last message: {:EXIT, #PID<0.974.0>, {{:badmatch, {:error, "socket closed"}}, [{NSQ.Connection.Buffer, :recv!, 2, [file: 'lib/nsq/connection/buffer.ex', line: 88]}, {NSQ.Connection.Initializer, :recv_nsq_response, 1, [file: 'lib/nsq/connection/initializer.ex', line: 201]}, {NSQ.Connection.Initializer, :identify, 1, [file: 'lib/nsq/connection/initializer.ex', line: 90]}, {NSQ.Connection.Initializer, :do_handshake, 1, [file: 'lib/nsq/connection/initializer.ex', line: 63]}, {NSQ.Connection.Initializer, :do_handshake!, 1, [file: 'lib/nsq/connection/initializer.ex', line: 73]}, {NSQ.Connection.Initializer, :connect, 1, [file: 'lib/nsq/connection/initializer.ex', line: 30]}, {NSQ.Connection, :init, 1, [file: 'lib/nsq/connection.ex', line: 99]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}
State: {:state, {#PID<0.977.0>, NSQ.Message.Supervisor}, :one_for_one, [], :undefined, 3, 5, [], 0, NSQ.Message.Supervisor, :ok}
[error] GenServer #PID<0.966.0> terminating
** (MatchError) no match of right hand side value: {:error, {{:EXIT, {{:badmatch, {:error, {{:badmatch, {:error, "socket closed"}}, [{NSQ.Connection.Buffer, :recv!, 2, [file: 'lib/nsq/connection/buffer.ex', line: 88]}, {NSQ.Connection.Initializer, :recv_nsq_response, 1, [file: 'lib/nsq/connection/initializer.ex', line: 201]}, {NSQ.Connection.Initializer, :identify, 1, [file: 'lib/nsq/connection/initializer.ex', line: 90]}, {NSQ.Connection.Initializer, :do_handshake, 1, [file: 'lib/nsq/connection/initializer.ex', line: 63]}, {NSQ.Connection.Initializer, :do_handshake!, 1, [file: 'lib/nsq/connection/initializer.ex', line: 73]}, {NSQ.Connection.Initializer, :connect, 1, [file: 'lib/nsq/connection/initializer.ex', line: 30]}, {NSQ.Connection, :init, 1, [file: 'lib/nsq/connection.ex', line: 99]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}}, [{NSQ.Connection, :start_link, 8, [file: 'lib/nsq/connection.ex', line: 82]}, {:supervisor, :do_start_child, 2, [file: 'supervisor.erl', line: 365]}, {:supervisor, :handle_start_child, 2, [file: 'supervisor.erl', line: 724]}, {:supervisor, :handle_call, 3, [file: 'supervisor.erl', line: 422]}, {:gen_server, :try_handle_call, 4, [file: 'gen_server.erl', line: 636]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 665]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}, {:child, :undefined, "parent:#PID<0.965.0>:conn:127.0.0.1:4151", {NSQ.Connection, :start_link, [#PID<0.965.0>, {"127.0.0.1", 4151}, %NSQ.Config{tls_key: nil, rdy_retry_delay: 5000, tls_min_version: nil, user_agent: nil, deflate_level: 6, hostname: nil, write_timeout: 1000, heartbeat_interval: 30000, max_reconnect_attempts: 30, backoff_strategy: :exponential, tls_insecure_skip_verify: false, output_buffer_size: 16384, lookupd_poll_jitter: 0.3, auth_secret: "", low_rdy_idle_timeout: 10000, event_manager: nil, backoff_multiplier: 1000, msg_timeout: 60000, lookupd_poll_interval: 60000, dial_timeout: 1000, client_id: nil, tls_cert: nil, nsqds: [{"127.0.0.1", 4150}, {"127.0.0.1", 4151}], snappy: false, read_timeout: 60000, sample_rate: 0, deflate: false, max_attempts: 5, output_buffer_timeout: 250, rdy_redistribute_interval: 5000, max_in_flight: 2500, nsqlookupds: [], tls_v1: false, message_handler: nil, max_requeue_delay: 900000, max_backoff_duration: 120000}, "tracks", nil, #PID<0.967.0>, #PID<0.968.0>]}, :temporary, 5000, :worker, [NSQ.Connection]}}}
    (elixir_nsq) lib/nsq/producer.ex:183: anonymous fn/3 in NSQ.Producer.connect_to_nsqds/3
    (elixir) lib/enum.ex:1270: Enum."-map/2-lists^map/1-0-"/2
    (elixir) lib/enum.ex:1270: Enum."-map/2-lists^map/1-0-"/2
    (elixir_nsq) lib/nsq/producer.ex:182: NSQ.Producer.connect_to_nsqds/3
    (elixir_nsq) lib/nsq/producer.ex:105: NSQ.Producer.init/1
    (stdlib) gen_server.erl:365: :gen_server.init_it/2
    (stdlib) gen_server.erl:333: :gen_server.init_it/6
    (stdlib) proc_lib.erl:247: :proc_lib.init_p_do_apply/3
Last message: {:EXIT, #PID<0.965.0>, {{:badmatch, {:error, {{:EXIT, {{:badmatch, {:error, {{:badmatch, {:error, "socket closed"}}, [{NSQ.Connection.Buffer, :recv!, 2, [file: 'lib/nsq/connection/buffer.ex', line: 88]}, {NSQ.Connection.Initializer, :recv_nsq_response, 1, [file: 'lib/nsq/connection/initializer.ex', line: 201]}, {NSQ.Connection.Initializer, :identify, 1, [file: 'lib/nsq/connection/initializer.ex', line: 90]}, {NSQ.Connection.Initializer, :do_handshake, 1, [file: 'lib/nsq/connection/initializer.ex', line: 63]}, {NSQ.Connection.Initializer, :do_handshake!, 1, [file: 'lib/nsq/connection/initializer.ex', line: 73]}, {NSQ.Connection.Initializer, :connect, 1, [file: 'lib/nsq/connection/initializer.ex', line: 30]}, {NSQ.Connection, :init, 1, [file: 'lib/nsq/connection.ex', line: 99]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}}, [{NSQ.Connection, :start_link, 8, [file: 'lib/nsq/connection.ex', line: 82]}, {:supervisor, :do_start_child, 2, [file: 'supervisor.erl', line: 365]}, {:supervisor, :handle_start_child, 2, [file: 'supervisor.erl', line: 724]}, {:supervisor, :handle_call, 3, [file: 'supervisor.erl', line: 422]}, {:gen_server, :try_handle_call, 4, [file: 'gen_server.erl', line: 636]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 665]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}, {:child, :undefined, "parent:#PID<0.965.0>:conn:127.0.0.1:4151", {NSQ.Connection, :start_link, [#PID<0.965.0>, {"127.0.0.1", 4151}, %NSQ.Config{tls_key: nil, rdy_retry_delay: 5000, tls_min_version: nil, user_agent: nil, deflate_level: 6, hostname: nil, write_timeout: 1000, heartbeat_interval: 30000, max_reconnect_attempts: 30, backoff_strategy: :exponential, tls_insecure_skip_verify: false, output_buffer_size: 16384, lookupd_poll_jitter: 0.3, auth_secret: "", low_rdy_idle_timeout: 10000, event_manager: nil, backoff_multiplier: 1000, msg_timeout: 60000, lookupd_poll_interval: 60000, dial_timeout: 1000, client_id: nil, tls_cert: nil, nsqds: [{"127.0.0.1", 4150}, {"127.0.0.1", 4151}], snappy: false, read_timeout: 60000, sample_rate: 0, deflate: false, max_attempts: 5, output_buffer_timeout: 250, rdy_redistribute_interval: 5000, max_in_flight: 2500, nsqlookupds: [], tls_v1: false, message_handler: nil, max_requeue_delay: 900000, ...}, "tracks", nil, #PID<0.967.0>, #PID<0.968.0>]}, :temporary, 5000, :worker, [NSQ.Connection]}}}}, [{NSQ.Producer, :"-connect_to_nsqds/3-fun-0-", 3, [file: 'lib/nsq/producer.ex', line: 183]}, {Enum, :"-map/2-lists^map/1-0-", 2, [file: 'lib/enum.ex', line: 1270]}, {Enum, :"-map/2-lists^map/1-0-", 2, [file: 'lib/enum.ex', line: 1270]}, {NSQ.Producer, :connect_to_nsqds, 3, [file: 'lib/nsq/producer.ex', line: 182]}, {NSQ.Producer, :init, 1, [file: 'lib/nsq/producer.ex', line: 105]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 365]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 333]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}
State: {:state, {#PID<0.966.0>, NSQ.Connection.Supervisor}, :one_for_one, [{:child, #PID<0.969.0>, "parent:#PID<0.965.0>:conn:127.0.0.1:4150", {NSQ.Connection, :start_link, :undefined}, :temporary, 5000, :worker, [NSQ.Connection]}], :undefined, 3, 5, [], 0, NSQ.Connection.Supervisor, :ok}

And the nsq logs output:

nsq_1         | [nsqd] 2017/11/26 21:55:06.689714 CLIENT(172.20.0.1:51444): desired protocol magic '  V2'
nsq_1         | [nsqd] 2017/11/26 21:55:06.689887 [172.20.0.1:51444] IDENTIFY: {ClientID:127.0.0.1:4150 (#PID<0.928.0>) Hostname:malcolm-desktop HeartbeatInterval:30000 OutputBufferSize:0 OutputBufferTimeout:250 FeatureNegotiation:true TLSv1:false Deflate:false DeflateLevel:6 Snappy:false SampleRate:0 UserAgent:elixir_nsq/1.0.3 MsgTimeout:60000}
nsq_1         | [nsqd] 2017/11/26 21:55:06.691477 PROTOCOL(V2): [172.20.0.1:51444] exiting ioloop
nsq_1         | [nsqd] 2017/11/26 21:55:06.691547 PROTOCOL(V2): [172.20.0.1:51444] exiting messagePump
nsq_1         | [nsqd] 2017/11/26 21:55:06.708451 TCP: new client(172.20.0.1:51448)
nsq_1         | [nsqd] 2017/11/26 21:55:06.708535 CLIENT(172.20.0.1:51448): desired protocol magic '  V2'
nsq_1         | [nsqd] 2017/11/26 21:55:06.708712 [172.20.0.1:51448] IDENTIFY: {ClientID:127.0.0.1:4150 (#PID<0.946.0>) Hostname:malcolm-desktop HeartbeatInterval:30000 OutputBufferSize:0 OutputBufferTimeout:250 FeatureNegotiation:true TLSv1:false Deflate:false DeflateLevel:6 Snappy:false SampleRate:0 UserAgent:elixir_nsq/1.0.3 MsgTimeout:60000}
nsq_1         | [nsqd] 2017/11/26 21:55:06.710622 PROTOCOL(V2): [172.20.0.1:51448] exiting ioloop
nsq_1         | [nsqd] 2017/11/26 21:55:06.710678 PROTOCOL(V2): [172.20.0.1:51448] exiting messagePump
nsq_1         | [nsqd] 2017/11/26 21:55:06.726224 TCP: new client(172.20.0.1:51456)
nsq_1         | [nsqd] 2017/11/26 21:55:06.726244 CLIENT(172.20.0.1:51456): desired protocol magic '  V2'
nsq_1         | [nsqd] 2017/11/26 21:55:06.726377 [172.20.0.1:51456] IDENTIFY: {ClientID:127.0.0.1:4150 (#PID<0.965.0>) Hostname:malcolm-desktop HeartbeatInterval:30000 OutputBufferSize:0 OutputBufferTimeout:250 FeatureNegotiation:true TLSv1:false Deflate:false DeflateLevel:6 Snappy:false SampleRate:0 UserAgent:elixir_nsq/1.0.3 MsgTimeout:60000}
nsq_1         | [nsqd] 2017/11/26 21:55:06.727777 PROTOCOL(V2): [172.20.0.1:51456] exiting ioloop
nsq_1         | [nsqd] 2017/11/26 21:55:06.727832 PROTOCOL(V2): [172.20.0.1:51456] exiting messagePump

[MaxPower15]

Ah, that's no fun. Can you tell me what version of nsq you're running, the command you started it with, and the version of the socket package is in your mix.lock file?

NSQ closes the connection when it runs into anything that it considers invalid and the point where it's failing for you is the first place we try to recv from the socket we've created. So I think there must be a bad config being passed, and that could be because of updates to NSQ that we're not accounting for or maybe just a part of the config that's not valid (though it looks okay to my eye). But if you want to play around with your config while I look into various version updates, that's something to double check.

[MaxPower15]

If it helps, my IDENTIFY output when running the tests here is like

{ShortID: LongID: ClientID:127.0.0.1:6750 (#PID<0.689.0>) Hostname:Maxs-MBP-2.fios-router.home HeartbeatInterval:30000 OutputBufferSize:0 OutputBufferTimeout:250 FeatureNegotiation:true TLSv1:false Deflate:false DeflateLevel:6 Snappy:false SampleRate:0 UserAgent:elixir_nsq/1.0.3 MsgTimeout:60000}

So that should be an example of a valid config, at least on v0.3.8.

[malcolmrebughini]

@MaxPower15 So my nsq version is 1.0.0-compat I'm running it inside some docker containers (I can send info via http by hand no problem).

My socket version is:
"socket": {:hex, :socket, "0.3.12", "4a6543815136503fee67eff0932da1742fad83f84c49130c854114153cc549a6", [], [], "hexpm"},

Tried downgrading socket to 0.3.8 just in case. But no luck, same error 😞

[MaxPower15]

Gotcha, thanks for testing. I just updated to 1.0.0-compat and was able to reproduce. I'll let you know what I find and hopefully push up a fix soon.

[chen-anders]

We're currently using 0.3.5 of the socket package as I recalled either the same or some other issue with newer versions.

[MaxPower15]

Hmm, scratch that repro I thought I found, sorry. The consumer specs are failing for 1.0.0-compat, but the error I saw for the producer was just caused by the test closing down a dependent process a little early. It had already passed though.

I'm going to look into the issues with the consumer and hope to have a fix for that. EDIT: These are all because we used the /put endpoint instead of /pub in our tests. Easy fix at least. SECOND EDIT: Bah, I just had old code locally, heh. Others already fixed this.

@malcolmrebughini Are you able to test without docker by any chance? Or perhaps debug that piece a little further? I'm wondering if there's a port forwarding issue, or something like that; maybe when NSQ tries to recv on its local socket, the container or VM blocks it? Not sure why that would happen, but I did a test of an invalid config locally with 1.0.0-compat and when it gets bad data, the output looks like this:

19:37:37 nsqd1.1       | [nsqd] 2017/11/26 19:37:37.967723 ERROR: [127.0.0.1:58412] - E_BAD_BODY IDENTIFY failed to decode JSON body - json: cannot unmarshal string into Go struct field identifyDataV2.feature_negotiation of type bool
19:37:37 nsqd1.1       | [nsqd] 2017/11/26 19:37:37.967742 PROTOCOL(V2): [127.0.0.1:58412] exiting ioloop
19:37:37 nsqd1.1       | [nsqd] 2017/11/26 19:37:37.967763 ERROR: client(127.0.0.1:58412) - E_BAD_BODY IDENTIFY failed to decode JSON body
19:37:37 nsqd1.1       | [nsqd] 2017/11/26 19:37:37.967769 PROTOCOL(V2): [127.0.0.1:58412] exiting messagePump

That is, NSQ says what kind of error it is (i.e. E_BAD_BODY here) and the exact field it had trouble with. Your output doesn't indicate any error, which I think means the connection was closed upstream, outside of nsqd. That leaves the socket's origin (the elixir_nsq client) and anything in between the origin and nsqd (i.e. docker in this case) that could be responsible.

Could you let me know the exact commandline args you've used to install/start nsq so I can test the same way locally?

[malcolmrebughini]

There seems to be something wrong with the application I'm writing. Cloned this repo and all tests passed.

With my app tried running a local nsq and still the same error (Just running nsqd with the default configuration).

This is an api made with Phoenix, when a certain endpoint its hit a message is sent to NSQ. I don't know if there should be any issues with this (elixir newbie here).

Anyways, I'll make a barebones example of what I'm trying to accomplish to share with you in the next couple of days.

Thank you for all your help!

[MaxPower15]

Ah, cool, thanks for testing that!

This is an api made with Phoenix, when a certain endpoint its hit a message is sent to NSQ. I don't know if there should be any issues with this (elixir newbie here).

Yeah, it's hard to say without knowing all the details of the API, but what I'd usually expect for that use case is that you add an NSQ.Producer.Supervisor to your supervision tree (as a supervisor, not a worker) and register a name for it. Then your phoenix requests can all send data to the same socket like NSQ.Producer.pub(MyProducerName, "the-data").

This explains the pattern I'm thinking of. https://www.amberbit.com/blog/2016/5/13/process-name-registration-in-elixir/

I mention that because it sounds like the producer you're creating is a dependent process of a phoenix request, which means it gets killed when the request process terminates.

Anyway, this issue prompted me to publish version 1.0.4 and it seems like things are basically working, so I'll close this issue. Thanks!

[MaxPower15]

I should mention, feel free to post on this thread for help/advice and potentially reopen if you can find a reproducible issue. Good luck!

…

On Sun, Nov 26, 2017 at 9:06 PM Malcolm Rebughini ***@***.***> wrote: There seems to be something wrong with the application I'm writing. Cloned this repo and all tests passed. With my app tried running a local nsq and still the same error (Just running nsqd with the default configuration). This is an api made with Phoenix, when a certain endpoint its hit a message is sent to NSQ. I don't know if there should be any issues with this (elixir newbie here). Anyways, I'll make a barebones example of what I'm trying to accomplish to share with you in the next couple of days. Thank you for all your help! — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#21 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAeJqKitun_o_XB_SrR62v9i39MxfNQQks5s6hk9gaJpZM4Qq76E> .

[malcolmrebughini]

Hey @MaxPower15 , sorry to bother you again.

I've made a quick example, that actually just adds 5 lines to a barebones Phoenix app.

If you go to /lib/phoenix_nsq/application.ex there I added the NSQ.Producer.Supervisor. I'm not sure that I did that right but for me it keeps crashing at startup with {:error, "socket closed"}.

Any ideas on what I did wrong or what could be happening?

A million thanks!

[MaxPower15]

Ah, thanks for putting that up, that's helpful. Assuming you're running just one instance of nsqd on the default port (4150), I think it's because you've got two nsqds configured to connect: one on 4150 and one on 4151. The default nsqd starts listening for TCP on 4150 and HTTP for 4151. And the config for nsqds is meant only to target the TCP ports.

Anyway, with that in mind, does it work for you if you change the nsqd config line at https://github.com/malcolmrebughini/phoenix-nsq-example/blob/53767c3a0e385e86f5e372397aa6d28d7e50bb32/lib/phoenix_nsq/application.ex#L18 to this?

    nsqds: ["127.0.0.1:4150"]

[malcolmrebughini]

It was that! Let's say that I'm not feeling smart after this 😬

Thanks a lot for your help!

[MaxPower15]

No worries, nsq port configs still get me years on, haha. Cheers!