Unexpected trailing sections: v1_0.delivery_annotations

[m-jayson]

I'm getting the below error whenever I'm consuming messages from the cluster

** {{unexpected_trailing_sections,{{'v1_0.delivery_annotations',[]},<<0,83,114,193,1,0,0,83,115,208,0,0,0,18,0,0,0,3,64,64,161,10,116,101,115,116,45,113,117,101,117,101,0,83,116,193,1,0,0,83,119,161,5,104,101,108,108,111,0,83,120,193,1,0>>}},[{rabbit_amqp1_0_message,assemble,4,[{file,"src/rabbit_amqp1_0_message.erl"},{line,104}]},{rabbit_amqp1_0_message,assemble,1,[{file,"src/rabbit_amqp1_0_message.erl"},{line,21}]},{rabbit_amqp1_0_incoming_link,transfer,4,[{file,"src/rabbit_amqp1_0_incoming_link.erl"},{line,138}]},{rabbit_amqp1_0_session_process,handle_control,2,[{file,"src/rabbit_amqp1_0_session_process.erl"},{line,253}]},{rabbit_amqp1_0_session_process,handle_cast,2,[{file,"src/rabbit_amqp1_0_session_process.erl"},{line,173}]},{gen_server2,handle_msg,2,[{file,"src/gen_server2.erl"},{line,1067}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]}
2020-09-27 19:01:26.332 [info] <0.1193.0> [{initial_call,{rabbit_amqp1_0_session_process,init,['Argument__1']}},{pid,<0.1193.0>},{registered_name,[]},{error_info,{exit,{{unexpected_trailing_sections,{{'v1_0.delivery_annotations',[]},<<0,83,114,193,1,0,0,83,115,208,0,0,0,18,0,0,0,3,64,64,161,10,116,101,115,116,45,113,117,101,117,101,0,83,116,193,1,0,0,83,119,161,5,104,101,108,108,111,0,83,120,193,1,0>>}},[{rabbit_amqp1_0_message,assemble,4,[{file,"src/rabbit_amqp1_0_message.erl"},{line,104}]},{rabbit_amqp1_0_message,assemble,1,[{file,"src/rabbit_amqp1_0_message.erl"},{line,21}]},{rabbit_amqp1_0_incoming_link,transfer,4,[{file,"src/rabbit_amqp1_0_incoming_link.erl"},{line,138}]},{rabbit_amqp1_0_session_process,handle_control,2,[{file,"src/rabbit_amqp1_0_session_process.erl"},{line,253}]},{rabbit_amqp1_0_session_process,handle_cast,2,[{file,"src/rabbit_amqp1_0_session_process.erl"},{line,173}]},{gen_server2,handle_msg,2,[{file,"src/gen_server2.erl"},{line,1067}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]},[{gen_server2,terminate,3,[{file,"src/gen_server2.erl"},{line,1183}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]}},{ancestors,[<0.1191.0>,<0.1188.0>,<0.1186.0>,<0.1185.0>,<0.897.0>,<0.896.0>,<0.895.0>,rabbit_sup,<0.272.0>]},{message_queue_len,1},{messages,[{'DOWN',#Ref<0.2318329786.1542979586.132055>,process,<0.1202.0>,normal}]},{links,[<0.1191.0>]},{dictionary,[{gen_server_call_timeout,60000},{{in,{uint,0}},{incoming_link,{utf8,<<"test-channel">>},<<>>,<<"test-queue">>,undefined,0,undefined,{ubyte,0},32768,[],{set,1,16,16,8,80,48,{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},{{[],[],[],[],[],[],[],[],[<<"test-queue">>],[],[],[],[],[],[],[]}}}}},{{credit_to,<0.1187.0>},197},{credit_flow_default_credit,{400,200}}]},{trap_exit,true},{status,running},{heap_size,2586},{stack_size,28},{reductions,5639}], []
2020-09-27 19:01:26.333 [error] <0.1193.0> CRASH REPORT Process <0.1193.0> with 0 neighbours exited with reason: {unexpected_trailing_sections,{{'v1_0.delivery_annotations',[]},<<0,83,114,193,1,0,0,83,115,208,0,0,0,18,0,0,0,3,64,64,161,10,116,101,115,116,45,113,117,101,117,101,0,83,116,193,1,0,0,83,119,161,5,104,101,108,108,111,0,83,120,193,1,0>>}} in rabbit_amqp1_0_message:assemble/4 line 104 in gen_server2:terminate/3 line 1183
2020-09-27 19:01:26.334 [error] <0.1191.0> Supervisor {<0.1191.0>,rabbit_amqp1_0_session_sup} had child channel started with rabbit_amqp1_0_session_process:start_link({0,<0.1187.0>,<0.1192.0>,{user,<<"rabbit-user">>,[administrator],[{rabbit_auth_backend_internal,...}]},...}) at <0.1193.0> exit with reason {unexpected_trailing_sections,{{'v1_0.delivery_annotations',[]},<<0,83,114,193,1,0,0,83,115,208,0,0,0,18,0,0,0,3,64,64,161,10,116,101,115,116,45,113,117,101,117,101,0,83,116,193,1,0,0,83,119,161,5,104,101,108,108,111,0,83,120,193,1,0>>}} in rabbit_amqp1_0_message:assemble/4 line 104 in context child_terminated
2020-09-27 19:01:26.335 [error] <0.1191.0> Supervisor {<0.1191.0>,rabbit_amqp1_0_session_sup} had child channel started with rabbit_amqp1_0_session_process:start_link({0,<0.1187.0>,<0.1192.0>,{user,<<"rabbit-user">>,[administrator],[{rabbit_auth_backend_internal,...}]},...}) at <0.1193.0> exit with reason reached_max_restart_intensity in context shutdown
2020-09-27 19:01:29.332 [error] <0.1187.0> closing AMQP connection <0.1187.0> (10.1.7.1:60751 -> 10.1.7.199:5672):
{handshake_error,running,<0.1193.0>,{{symbol,<<"amqp:internal-error">>},"Session error: ~p~n~p~n",[{unexpected_trailing_sections,{{'v1_0.delivery_annotations',[]},<<0,83,114,193,1,0,0,83,115,208,0,0,0,18,0,0,0,3,64,64,161,10,116,101,115,116,45,113,117,101,117,101,0,83,116,193,1,0,0,83,119,161,5,104,101,108,108,111,0,83,120,193,1,0>>}},[{rabbit_amqp1_0_message,assemble,4,[{file,"src/rabbit_amqp1_0_message.erl"},{line,104}]},{rabbit_amqp1_0_message,assemble,1,[{file,"src/rabbit_amqp1_0_message.erl"},{line,21}]},{rabbit_amqp1_0_incoming_link,transfer,4,[{file,"src/rabbit_amqp1_0_incoming_link.erl"},{line,138}]},{rabbit_amqp1_0_session_process,handle_control,2,[{file,"src/rabbit_amqp1_0_session_process.erl"},{line,253}]},{rabbit_amqp1_0_session_process,handle_cast,2,[{file,"src/rabbit_amqp1_0_session_process.erl"},{line,173}]},{gen_server2,handle_msg,2,[{file,"src/gen_server2.erl"},{line,1067}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]]}}

here is the below kubernetes setup and config

apiVersion: v1
kind: ConfigMap
metadata:
  name: rabbitmq-config
data:
  enabled_plugins: |
    [rabbitmq_federation,rabbitmq_management,rabbitmq_peer_discovery_k8s,rabbitmq_amqp1_0].
  rabbitmq.conf: |
    loopback_users.guest = false
    listeners.tcp.default = 5672
    cluster_formation.peer_discovery_backend  = rabbit_peer_discovery_k8s
    cluster_formation.k8s.host = kubernetes.default.svc.cluster.local
    cluster_formation.k8s.address_type = hostname
    cluster_formation.node_cleanup.only_log_warning = true
    ##cluster_formation.peer_discovery_backend = rabbit_peer_discovery_classic_config
    ##cluster_formation.classic_config.nodes.1 = rabbit@rabbitmq-0.rabbitmq.rabbits.svc.cluster.local
    ##cluster_formation.classic_config.nodes.2 = rabbit@rabbitmq-1.rabbitmq.rabbits.svc.cluster.local
    ##cluster_formation.classic_config.nodes.3 = rabbit@rabbitmq-2.rabbitmq.rabbits.svc.cluster.local
    ##rabbitmq_amqp1_0
# …

Not really sure what I missed here.

[michaelklishin]

@mgonzaga1990 we need a piece of AMQP 1.0 client code that reproduces this.

[m-jayson]

@michaelklishin cannot connect.zip

there is a docker-compose there that you could spin up instead of my kubernetes setup.

It's a quarkus app btw.

[michaelklishin]

Thanks. We will get to it in the next week or two. Quite likely it's an AMQP 1.0 feature that this plugin did not implement because it's not particularly commonly used.

[m-jayson]

@michaelklishin thanks appreciated let me know you once you have an update on this. :)

[kjnilsson]

This error occurs on an "incoming" link, i.e. when messages are published. For some reason a delivery annotations section is following a footer which cannot be correct so must be something the client sends that is either wrong or the server isn't parsing correctly.

[m-jayson]

@kjnilsson might be the issue on the library i'm using but not sure.. Since I'm using library for 1.0 AMQP

[michaelklishin]

So far we have evidence of something odd being sent by the client. One easy way to narrow things down is to try a couple more AMQP 1.0 implementations and see how they behave.

[m-jayson]

@michaelklishin so this is to say that the possible issue is in library i'm using?

[michaelklishin]

Yes, you cannot assume that clients always send correct payloads.

[Postremus]

@michaelklishin @mgonzaga1990

I was able to confirm, that this is most likely an regression in smallrye-reactive-messaging. It works if I downgrade to an older version of the client,

I opened https://github.com/smallrye/smallrye-reactive-messaging/issues/807 for this.

[m-jayson]

@Postremus what version did you use to test that worked?

[Postremus]

@mgonzaga1990 1.6.1.Final worked for me. @michaelklishin This is definitly now a problem in smallrye reactive messaging - see the fix in: https://github.com/smallrye/smallrye-reactive-messaging/pull/812

[m-jayson]

it will be fixed on the next relase of smallrye messeging

On Thu, Oct 15, 2020, 5:14 AM Martin Panzer notifications@github.com wrote:

@michaelklishin https://github.com/michaelklishin @mgonzaga1990 https://github.com/mgonzaga1990

I was able to confirm, that this is most likely an regression in smallrye-reactive-messaging. It works if I downgrade to an older version of the client,

I opened smallrye/smallrye-reactive-messaging#807 https://github.com/smallrye/smallrye-reactive-messaging/issues/807 for this.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/rabbitmq/rabbitmq-amqp1.0/issues/102#issuecomment-708663873, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFBKRMYLBV564VWU37SOEDTSKYIE5ANCNFSM4R3XIWHQ .

[michaelklishin]

Thank you for following up.