Unexpected dependency between shovels

[inikulshin]

We use RabbitMQ 3.8.16, Erlang 24.1.7 on the machine the logs from, 3.8.16 + 24.0.4 on CloudAMQP.

I tried to make our shovels work with verify=verify_peer, and I made the following testing actions (from browser):

1. Create shovel zzz with both URIs amqps://varadmrabbit-d4cc9fdc:[redacted]@hasty-crimson-flamingo.rmq3.cloudamqp.com:5671/d4cc9fdc-2e48-4135-9863-87c9e9859351?cacertfile=C%3A%5CWorkingShare%5Crmqcluster_service%5Ccacert.pem&verify=verify_peer&heartbeat=900&server_name_indication=hasty-crimson-flamingo.rmq3.cloudamqp.com.
2. The shovel zzz fails to start.
   This hostname_check_failed failure is also unexpected, openssl s_client ... -verify_hostname hasty-crimson-flamingo.rmq3.cloudamqp.com succeeds, probably this is related to the following.
3. Create shovel xxx with both URIs amqps://varadmrabbit-d4cc9fdc:[redacted]@hasty-crimson-flamingo.rmq3.cloudamqp.com:5671/d4cc9fdc-2e48-4135-9863-87c9e9859351?cacertfile=C%3A%5CWorkingShare%5Crmqcluster_service%5Ccacert.pem&verify=verify_peer&heartbeat=900&server_name_indication=disable. The only difference from zzz is disabled SNI.
4. Shovels xxx succeeds to start.
5. Unexpectedly, shovel zzz also succeeds to start!
6. After shovel zzz restart , the unexpected behavior didn't reproduced. Repeating 1-5 also didn't reproduce.

Also, similar shovel with server_name_indication=*.rmq3.cloudamqp.com succeeds. It looks like in hostname matching process the wildcard pattern is used as a hostname, and vice versa.

2022-01-17 15:58:57.310 [error] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} had child {<<"/">>,<<"zzz">>} started with rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at {restarting,<0.20290.17>} exit with reason shutdown in context child_terminated
2022-01-17 15:58:57.311 [debug] <0.20304.17> Initialising a Shovel 'zzz' in virtual host '/' of type 'dynamic'
2022-01-17 15:58:57.312 [debug] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} started rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at pid <0.20304.17>
2022-01-17 15:58:57.312 [debug] <0.20305.17> Supervisor {<0.20305.17>,amqp_connection_sup} started amqp_connection_type_sup:start_link() at pid <0.20306.17>
2022-01-17 15:58:57.312 [debug] <0.20305.17> Supervisor {<0.20305.17>,amqp_connection_sup} started amqp_gen_connection:start_link(<0.20306.17>, {amqp_params_network,<<"varadmrabbit-d4cc9fdc">>,{encrypted,<<"ulw4MK5UkAhtaGVW2Fr9qWKJPrGuBZX8OiJ...">>},...}) at pid <0.20307.17>
2022-01-17 15:58:57.332 [error] <0.20304.17> Shovel 'zzz' failed to connect (URI: amqps://hasty-crimson-flamingo.rmq3.cloudamqp.com:5671/d4cc9fdc-2e48-4135-9863-87c9e9859351): {tls_alert,{handshake_failure,"TLS client: In state certify at ssl_handshake.erl:2017 generated CLIENT ALERT: Fatal - Handshake Failure\n {bad_cert,hostname_check_failed}"}}
2022-01-17 15:58:57.332 [error] <0.20304.17> Shovel 'zzz' has no more URIs to try for connection
2022-01-17 15:58:57.333 [error] <0.20304.17> Shovel 'zzz' could not connect, caught exception error:failed_to_connect_using_provided_uris
2022-01-17 15:58:57.333 [error] <0.20304.17> Shovel 'zzz' could not connect to source
2022-01-17 15:58:57.333 [error] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} had child {<<"/">>,<<"zzz">>} started with rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at <0.20304.17> exit with reason shutdown in context child_terminated
2022-01-17 15:58:57.355 [debug] <0.20314.17> User 'VaronisRabbitMQ' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:58:58.578 [debug] <0.20316.17> User 'qq' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:58:58.583 [debug] <0.20317.17> User 'qq' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:59:02.335 [error] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} had child {<<"/">>,<<"zzz">>} started with rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at {restarting,<0.20304.17>} exit with reason shutdown in context child_terminated
2022-01-17 15:59:02.336 [debug] <0.20318.17> Initialising a Shovel 'zzz' in virtual host '/' of type 'dynamic'
2022-01-17 15:59:02.337 [debug] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} started rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at pid <0.20318.17>
2022-01-17 15:59:02.337 [debug] <0.20319.17> Supervisor {<0.20319.17>,amqp_connection_sup} started amqp_connection_type_sup:start_link() at pid <0.20320.17>
2022-01-17 15:59:02.338 [debug] <0.20319.17> Supervisor {<0.20319.17>,amqp_connection_sup} started amqp_gen_connection:start_link(<0.20320.17>, {amqp_params_network,<<"varadmrabbit-d4cc9fdc">>,{encrypted,<<"9OnVbktwJMexxitv571+50guQHPqRuxa6G3...">>},...}) at pid <0.20321.17>
2022-01-17 15:59:02.356 [debug] <0.20325.17> User 'VaronisRabbitMQ' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:59:02.393 [error] <0.20318.17> Shovel 'zzz' failed to connect (URI: amqps://hasty-crimson-flamingo.rmq3.cloudamqp.com:5671/d4cc9fdc-2e48-4135-9863-87c9e9859351): {tls_alert,{handshake_failure,"TLS client: In state certify at ssl_handshake.erl:2017 generated CLIENT ALERT: Fatal - Handshake Failure\n {bad_cert,hostname_check_failed}"}}
2022-01-17 15:59:02.393 [error] <0.20318.17> Shovel 'zzz' has no more URIs to try for connection
2022-01-17 15:59:02.393 [error] <0.20318.17> Shovel 'zzz' could not connect, caught exception error:failed_to_connect_using_provided_uris
2022-01-17 15:59:02.393 [error] <0.20318.17> Shovel 'zzz' could not connect to source
2022-01-17 15:59:02.393 [error] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} had child {<<"/">>,<<"zzz">>} started with rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at <0.20318.17> exit with reason shutdown in context child_terminated
2022-01-17 15:59:03.021 [debug] <0.20330.17> User 'qq' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:59:03.021 [debug] <0.20330.17> Asked to set or update runtime parameter 'xxx' in vhost '/' for component 'shovel', value: [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"amqp091">>},{<<"dest-queue">>,<<"x2">>},{<<"dest-uri">>,<<"amqps://varadmrabbit-d4cc9fdc:ythiirQYDODFPJAm5zrbdvQlk5CTIU@hasty-crimson-flamingo.rmq3.cloudamqp.com:5671/d4cc9fdc-2e48-4135-9863-87c9e9859351?cacertfile=C%3A%5CWorkingShare%5Crmqcluster_service%5Ccacert.pem&verify=verify_peer&heartbeat=900&server_name_indication=disable">>},{<<"src-delete-after">>,<<"never">>},{<<"src-protocol">>,<<"amqp091">>},{<<"src-queue">>,<<"x1">>},{<<"src-uri">>,<<"amqps://varadmrabbit-d4cc9fdc:ythiirQYDODFPJAm5zrbdvQlk5CTIU@hasty-crimson-flamingo.rmq3.cloudamqp.com:5671/d4cc9fdc-2e48-4135-9863-87c9e9859351?cacertfile=C%3A%5CWorkingShare%5Crmqcluster_service%5Ccacert.pem&verify=verify_peer&heartbeat=900&server_name_indication=disable">>}]
2022-01-17 15:59:03.031 [debug] <0.20346.17> Shovel 'xxx' in virtual host '/' will use reconnection delay of 5
2022-01-17 15:59:03.032 [debug] <0.20347.17> Initialising a Shovel 'xxx' in virtual host '/' of type 'dynamic'
2022-01-17 15:59:03.032 [debug] <0.20346.17> Supervisor {<0.20346.17>,rabbit_shovel_dyn_worker_sup} started rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"xxx">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at pid <0.20347.17>
2022-01-17 15:59:03.033 [debug] <0.1460.0> Supervisor {<0.1460.0>,mirrored_supervisor_sups} started rabbit_shovel_dyn_worker_sup:start_link({<<"/">>,<<"xxx">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at pid <0.20346.17>
2022-01-17 15:59:03.033 [debug] <0.20348.17> Supervisor {<0.20348.17>,amqp_connection_sup} started amqp_connection_type_sup:start_link() at pid <0.20349.17>
2022-01-17 15:59:03.033 [debug] <0.20348.17> Supervisor {<0.20348.17>,amqp_connection_sup} started amqp_gen_connection:start_link(<0.20349.17>, {amqp_params_network,<<"varadmrabbit-d4cc9fdc">>,{encrypted,<<"9XkeTQi2/p2euldOCRpwGtXYgcAoMoq6HOo...">>},...}) at pid <0.20350.17>
2022-01-17 15:59:03.036 [debug] <0.20351.17> User 'qq' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:59:03.047 [debug] <0.20354.17> User 'qq' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:59:03.050 [debug] <0.20349.17> Supervisor {<0.20349.17>,amqp_connection_type_sup} started amqp_channel_sup_sup:start_link(network, <0.20350.17>, <<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>) at pid <0.20355.17>
2022-01-17 15:59:03.050 [debug] <0.20349.17> Supervisor {<0.20349.17>,amqp_connection_type_sup} started amqp_channels_manager:start_link(<0.20350.17>, <<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>, <0.20355.17>) at pid <0.20356.17>
2022-01-17 15:59:03.050 [debug] <0.20349.17> Supervisor {<0.20349.17>,amqp_connection_type_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140369>,tls_connection,undefined},[<0.20353.17>,<0.20352.17>]}, 0, 4096, rabbit_framing_amqp_0_9_1, <0.20350.17>, <<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>, false, 1000000000) at pid <0.20357.17>
2022-01-17 15:59:03.050 [debug] <0.20349.17> Supervisor {<0.20349.17>,amqp_connection_type_sup} started amqp_main_reader:start_link({sslsocket,{gen_tcp,#Port<0.140369>,tls_connection,undefined},[<0.20353.17>,<0.20352.17>]}, <0.20350.17>, <0.20356.17>, {method,rabbit_framing_amqp_0_9_1}, <<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>) at pid <0.20358.17>
2022-01-17 15:59:03.054 [debug] <0.20349.17> Supervisor {<0.20349.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_sender({sslsocket,{gen_tcp,#Port<0.140369>,tls_connection,undefined},[<0.20353.17>,<0.20352.17>]}, 900, #Fun<amqp_network_connection.2.15045815>, {heartbeat_sender,<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>}) at pid <0.20359.17>
2022-01-17 15:59:03.054 [debug] <0.20349.17> Supervisor {<0.20349.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_receiver({sslsocket,{gen_tcp,#Port<0.140369>,tls_connection,undefined},[<0.20353.17>,<0.20352.17>]}, 900, #Fun<amqp_network_connection.3.15045815>, {heartbeat_receiver,<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>}) at pid <0.20360.17>
2022-01-17 15:59:03.057 [debug] <0.20361.17> Supervisor {<0.20361.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,1}) at pid <0.20362.17>
2022-01-17 15:59:03.057 [debug] <0.20361.17> Supervisor {<0.20361.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20350.17>, 1, <0.20362.17>, {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,1}) at pid <0.20363.17>
2022-01-17 15:59:03.057 [debug] <0.20361.17> Supervisor {<0.20361.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140369>,tls_connection,undefined},[<0.20353.17>,<0.20352.17>]}, 1, 131072, rabbit_framing_amqp_0_9_1, <0.20363.17>, {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,1}, false, 1000000000) at pid <0.20364.17>
2022-01-17 15:59:03.059 [debug] <0.20347.17> Shovel 'xxx' connected to source
2022-01-17 15:59:03.060 [debug] <0.20365.17> Supervisor {<0.20365.17>,amqp_connection_sup} started amqp_connection_type_sup:start_link() at pid <0.20366.17>
2022-01-17 15:59:03.060 [debug] <0.20365.17> Supervisor {<0.20365.17>,amqp_connection_sup} started amqp_gen_connection:start_link(<0.20366.17>, {amqp_params_network,<<"varadmrabbit-d4cc9fdc">>,{encrypted,<<"0m3V0X7VRwX0Kgdyp5001ws6htNIWwkzizJ...">>},...}) at pid <0.20367.17>
2022-01-17 15:59:03.067 [debug] <0.20366.17> Supervisor {<0.20366.17>,amqp_connection_type_sup} started amqp_channel_sup_sup:start_link(network, <0.20367.17>, <<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>) at pid <0.20370.17>
2022-01-17 15:59:03.067 [debug] <0.20366.17> Supervisor {<0.20366.17>,amqp_connection_type_sup} started amqp_channels_manager:start_link(<0.20367.17>, <<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>, <0.20370.17>) at pid <0.20371.17>
2022-01-17 15:59:03.067 [debug] <0.20366.17> Supervisor {<0.20366.17>,amqp_connection_type_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140364>,tls_connection,undefined},[<0.20369.17>,<0.20368.17>]}, 0, 4096, rabbit_framing_amqp_0_9_1, <0.20367.17>, <<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>, false, 1000000000) at pid <0.20372.17>
2022-01-17 15:59:03.067 [debug] <0.20366.17> Supervisor {<0.20366.17>,amqp_connection_type_sup} started amqp_main_reader:start_link({sslsocket,{gen_tcp,#Port<0.140364>,tls_connection,undefined},[<0.20369.17>,<0.20368.17>]}, <0.20367.17>, <0.20371.17>, {method,rabbit_framing_amqp_0_9_1}, <<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>) at pid <0.20373.17>
2022-01-17 15:59:03.070 [debug] <0.20366.17> Supervisor {<0.20366.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_sender({sslsocket,{gen_tcp,#Port<0.140364>,tls_connection,undefined},[<0.20369.17>,<0.20368.17>]}, 900, #Fun<amqp_network_connection.2.15045815>, {heartbeat_sender,<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>}) at pid <0.20374.17>
2022-01-17 15:59:03.070 [debug] <0.20366.17> Supervisor {<0.20366.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_receiver({sslsocket,{gen_tcp,#Port<0.140364>,tls_connection,undefined},[<0.20369.17>,<0.20368.17>]}, 900, #Fun<amqp_network_connection.3.15045815>, {heartbeat_receiver,<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>}) at pid <0.20375.17>
2022-01-17 15:59:03.073 [debug] <0.20376.17> Supervisor {<0.20376.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,1}) at pid <0.20377.17>
2022-01-17 15:59:03.073 [debug] <0.20376.17> Supervisor {<0.20376.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20367.17>, 1, <0.20377.17>, {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,1}) at pid <0.20378.17>
2022-01-17 15:59:03.073 [debug] <0.20376.17> Supervisor {<0.20376.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140364>,tls_connection,undefined},[<0.20369.17>,<0.20368.17>]}, 1, 131072, rabbit_framing_amqp_0_9_1, <0.20378.17>, {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,1}, false, 1000000000) at pid <0.20379.17>
2022-01-17 15:59:03.075 [debug] <0.20347.17> Shovel 'xxx' connected to destination
2022-01-17 15:59:03.075 [debug] <0.20380.17> Supervisor {<0.20380.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,2}) at pid <0.20381.17>
2022-01-17 15:59:03.075 [debug] <0.20380.17> Supervisor {<0.20380.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20367.17>, 2, <0.20381.17>, {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,2}) at pid <0.20382.17>
2022-01-17 15:59:03.076 [debug] <0.20380.17> Supervisor {<0.20380.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140364>,tls_connection,undefined},[<0.20369.17>,<0.20368.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20382.17>, {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20383.17>
2022-01-17 15:59:03.078 [debug] <0.20384.17> Supervisor {<0.20384.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,2}) at pid <0.20385.17>
2022-01-17 15:59:03.078 [debug] <0.20384.17> Supervisor {<0.20384.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20367.17>, 2, <0.20385.17>, {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,2}) at pid <0.20386.17>
2022-01-17 15:59:03.079 [debug] <0.20384.17> Supervisor {<0.20384.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140364>,tls_connection,undefined},[<0.20369.17>,<0.20368.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20386.17>, {<<"client 10.188.34.37:6659 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20387.17>
2022-01-17 15:59:03.091 [debug] <0.20388.17> Supervisor {<0.20388.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,2}) at pid <0.20389.17>
2022-01-17 15:59:03.091 [debug] <0.20388.17> Supervisor {<0.20388.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20350.17>, 2, <0.20389.17>, {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,2}) at pid <0.20390.17>
2022-01-17 15:59:03.091 [debug] <0.20388.17> Supervisor {<0.20388.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140369>,tls_connection,undefined},[<0.20353.17>,<0.20352.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20390.17>, {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20391.17>
2022-01-17 15:59:03.097 [debug] <0.20392.17> Supervisor {<0.20392.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,2}) at pid <0.20393.17>
2022-01-17 15:59:03.097 [debug] <0.20392.17> Supervisor {<0.20392.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20350.17>, 2, <0.20393.17>, {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,2}) at pid <0.20394.17>
2022-01-17 15:59:03.097 [debug] <0.20392.17> Supervisor {<0.20392.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140369>,tls_connection,undefined},[<0.20353.17>,<0.20352.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20394.17>, {<<"client 10.188.34.37:6658 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20395.17>
2022-01-17 15:59:03.111 [debug] <0.20347.17> Shovel 'xxx' has finished setting up its topology
2022-01-17 15:59:06.117 [debug] <0.20396.17> User 'qq' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:59:06.117 [debug] <0.20396.17> rabbit_access_control:check_vhost_access result: {'EXIT',{amqp_error,not_allowed,"access to vhost 'panzura' refused for user 'qq'",none}}
2022-01-17 15:59:06.118 [debug] <0.20396.17> rabbit_access_control:check_vhost_access result: {'EXIT',{amqp_error,not_allowed,"access to vhost 'ctera' refused for user 'qq'",none}}
2022-01-17 15:59:06.118 [debug] <0.20396.17> rabbit_access_control:check_vhost_access result: {'EXIT',{amqp_error,not_allowed,"access to vhost 'nasuni' refused for user 'qq'",none}}
2022-01-17 15:59:06.118 [debug] <0.20396.17> rabbit_access_control:check_vhost_access result: {'EXIT',{amqp_error,not_allowed,"access to vhost 'cohesity' refused for user 'qq'",none}}
2022-01-17 15:59:06.118 [debug] <0.20396.17> rabbit_access_control:check_vhost_access result: {'EXIT',{amqp_error,not_allowed,"access to vhost 'nutanix' refused for user 'qq'",none}}
2022-01-17 15:59:07.358 [debug] <0.20400.17> User 'VaronisRabbitMQ' authenticated successfully by backend rabbit_auth_backend_internal
2022-01-17 15:59:07.396 [error] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} had child {<<"/">>,<<"zzz">>} started with rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at {restarting,<0.20318.17>} exit with reason shutdown in context child_terminated
2022-01-17 15:59:07.397 [debug] <0.20401.17> Initialising a Shovel 'zzz' in virtual host '/' of type 'dynamic'
2022-01-17 15:59:07.397 [debug] <0.19688.17> Supervisor {<0.19688.17>,rabbit_shovel_dyn_worker_sup} started rabbit_shovel_worker:start_link(dynamic, {<<"/">>,<<"zzz">>}, [{<<"ack-mode">>,<<"on-confirm">>},{<<"dest-add-forward-headers">>,false},{<<"dest-protocol">>,<<"...">>},...]) at pid <0.20401.17>
2022-01-17 15:59:07.398 [debug] <0.20402.17> Supervisor {<0.20402.17>,amqp_connection_sup} started amqp_connection_type_sup:start_link() at pid <0.20403.17>
2022-01-17 15:59:07.398 [debug] <0.20402.17> Supervisor {<0.20402.17>,amqp_connection_sup} started amqp_gen_connection:start_link(<0.20403.17>, {amqp_params_network,<<"varadmrabbit-d4cc9fdc">>,{encrypted,<<"bR7jdDGoucySB4NT+rL10uvvhEeUfHeD5Eg...">>},...}) at pid <0.20404.17>
2022-01-17 15:59:07.407 [debug] <0.20403.17> Supervisor {<0.20403.17>,amqp_connection_type_sup} started amqp_channel_sup_sup:start_link(network, <0.20404.17>, <<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>) at pid <0.20407.17>
2022-01-17 15:59:07.407 [debug] <0.20403.17> Supervisor {<0.20403.17>,amqp_connection_type_sup} started amqp_channels_manager:start_link(<0.20404.17>, <<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>, <0.20407.17>) at pid <0.20408.17>
2022-01-17 15:59:07.408 [debug] <0.20403.17> Supervisor {<0.20403.17>,amqp_connection_type_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140371>,tls_connection,undefined},[<0.20406.17>,<0.20405.17>]}, 0, 4096, rabbit_framing_amqp_0_9_1, <0.20404.17>, <<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>, false, 1000000000) at pid <0.20409.17>
2022-01-17 15:59:07.408 [debug] <0.20403.17> Supervisor {<0.20403.17>,amqp_connection_type_sup} started amqp_main_reader:start_link({sslsocket,{gen_tcp,#Port<0.140371>,tls_connection,undefined},[<0.20406.17>,<0.20405.17>]}, <0.20404.17>, <0.20408.17>, {method,rabbit_framing_amqp_0_9_1}, <<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>) at pid <0.20410.17>
2022-01-17 15:59:07.413 [debug] <0.20403.17> Supervisor {<0.20403.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_sender({sslsocket,{gen_tcp,#Port<0.140371>,tls_connection,undefined},[<0.20406.17>,<0.20405.17>]}, 900, #Fun<amqp_network_connection.2.15045815>, {heartbeat_sender,<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>}) at pid <0.20412.17>
2022-01-17 15:59:07.413 [debug] <0.20403.17> Supervisor {<0.20403.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_receiver({sslsocket,{gen_tcp,#Port<0.140371>,tls_connection,undefined},[<0.20406.17>,<0.20405.17>]}, 900, #Fun<amqp_network_connection.3.15045815>, {heartbeat_receiver,<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>}) at pid <0.20413.17>
2022-01-17 15:59:07.416 [debug] <0.20414.17> Supervisor {<0.20414.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,1}) at pid <0.20415.17>
2022-01-17 15:59:07.416 [debug] <0.20414.17> Supervisor {<0.20414.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20404.17>, 1, <0.20415.17>, {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,1}) at pid <0.20416.17>
2022-01-17 15:59:07.416 [debug] <0.20414.17> Supervisor {<0.20414.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140371>,tls_connection,undefined},[<0.20406.17>,<0.20405.17>]}, 1, 131072, rabbit_framing_amqp_0_9_1, <0.20416.17>, {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,1}, false, 1000000000) at pid <0.20417.17>
2022-01-17 15:59:07.418 [debug] <0.20401.17> Shovel 'zzz' connected to source
2022-01-17 15:59:07.419 [debug] <0.20418.17> Supervisor {<0.20418.17>,amqp_connection_sup} started amqp_connection_type_sup:start_link() at pid <0.20419.17>
2022-01-17 15:59:07.419 [debug] <0.20418.17> Supervisor {<0.20418.17>,amqp_connection_sup} started amqp_gen_connection:start_link(<0.20419.17>, {amqp_params_network,<<"varadmrabbit-d4cc9fdc">>,{encrypted,<<"Th5K689WprZ0kC5T/6k0I++ot5bfk+HUV9I...">>},...}) at pid <0.20420.17>
2022-01-17 15:59:07.425 [debug] <0.20419.17> Supervisor {<0.20419.17>,amqp_connection_type_sup} started amqp_channel_sup_sup:start_link(network, <0.20420.17>, <<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>) at pid <0.20423.17>
2022-01-17 15:59:07.425 [debug] <0.20419.17> Supervisor {<0.20419.17>,amqp_connection_type_sup} started amqp_channels_manager:start_link(<0.20420.17>, <<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>, <0.20423.17>) at pid <0.20424.17>
2022-01-17 15:59:07.425 [debug] <0.20419.17> Supervisor {<0.20419.17>,amqp_connection_type_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140372>,tls_connection,undefined},[<0.20422.17>,<0.20421.17>]}, 0, 4096, rabbit_framing_amqp_0_9_1, <0.20420.17>, <<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>, false, 1000000000) at pid <0.20425.17>
2022-01-17 15:59:07.425 [debug] <0.20419.17> Supervisor {<0.20419.17>,amqp_connection_type_sup} started amqp_main_reader:start_link({sslsocket,{gen_tcp,#Port<0.140372>,tls_connection,undefined},[<0.20422.17>,<0.20421.17>]}, <0.20420.17>, <0.20424.17>, {method,rabbit_framing_amqp_0_9_1}, <<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>) at pid <0.20426.17>
2022-01-17 15:59:07.430 [debug] <0.20419.17> Supervisor {<0.20419.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_sender({sslsocket,{gen_tcp,#Port<0.140372>,tls_connection,undefined},[<0.20422.17>,<0.20421.17>]}, 900, #Fun<amqp_network_connection.2.15045815>, {heartbeat_sender,<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>}) at pid <0.20427.17>
2022-01-17 15:59:07.430 [debug] <0.20419.17> Supervisor {<0.20419.17>,amqp_connection_type_sup} started rabbit_heartbeat:start_heartbeat_receiver({sslsocket,{gen_tcp,#Port<0.140372>,tls_connection,undefined},[<0.20422.17>,<0.20421.17>]}, 900, #Fun<amqp_network_connection.3.15045815>, {heartbeat_receiver,<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>}) at pid <0.20428.17>
2022-01-17 15:59:07.433 [debug] <0.20429.17> Supervisor {<0.20429.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,1}) at pid <0.20430.17>
2022-01-17 15:59:07.433 [debug] <0.20429.17> Supervisor {<0.20429.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20420.17>, 1, <0.20430.17>, {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,1}) at pid <0.20431.17>
2022-01-17 15:59:07.433 [debug] <0.20429.17> Supervisor {<0.20429.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140372>,tls_connection,undefined},[<0.20422.17>,<0.20421.17>]}, 1, 131072, rabbit_framing_amqp_0_9_1, <0.20431.17>, {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,1}, false, 1000000000) at pid <0.20432.17>
2022-01-17 15:59:07.436 [debug] <0.20401.17> Shovel 'zzz' connected to destination
2022-01-17 15:59:07.436 [debug] <0.20433.17> Supervisor {<0.20433.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,2}) at pid <0.20434.17>
2022-01-17 15:59:07.436 [debug] <0.20433.17> Supervisor {<0.20433.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20420.17>, 2, <0.20434.17>, {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,2}) at pid <0.20435.17>
2022-01-17 15:59:07.437 [debug] <0.20433.17> Supervisor {<0.20433.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140372>,tls_connection,undefined},[<0.20422.17>,<0.20421.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20435.17>, {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20436.17>
2022-01-17 15:59:07.441 [debug] <0.20437.17> Supervisor {<0.20437.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,2}) at pid <0.20438.17>
2022-01-17 15:59:07.441 [debug] <0.20437.17> Supervisor {<0.20437.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20420.17>, 2, <0.20438.17>, {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,2}) at pid <0.20439.17>
2022-01-17 15:59:07.441 [debug] <0.20437.17> Supervisor {<0.20437.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140372>,tls_connection,undefined},[<0.20422.17>,<0.20421.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20439.17>, {<<"client 10.188.34.37:6663 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20440.17>
2022-01-17 15:59:07.459 [debug] <0.20441.17> Supervisor {<0.20441.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,2}) at pid <0.20442.17>
2022-01-17 15:59:07.459 [debug] <0.20441.17> Supervisor {<0.20441.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20404.17>, 2, <0.20442.17>, {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,2}) at pid <0.20443.17>
2022-01-17 15:59:07.460 [debug] <0.20441.17> Supervisor {<0.20441.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140371>,tls_connection,undefined},[<0.20406.17>,<0.20405.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20443.17>, {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20444.17>
2022-01-17 15:59:07.471 [debug] <0.20445.17> Supervisor {<0.20445.17>,amqp_channel_sup} started amqp_gen_consumer:start_link(amqp_selective_consumer, [], {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,2}) at pid <0.20446.17>
2022-01-17 15:59:07.471 [debug] <0.20445.17> Supervisor {<0.20445.17>,amqp_channel_sup} started amqp_channel:start_link(network, <0.20404.17>, 2, <0.20446.17>, {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,2}) at pid <0.20447.17>
2022-01-17 15:59:07.471 [debug] <0.20445.17> Supervisor {<0.20445.17>,amqp_channel_sup} started rabbit_writer:start_link({sslsocket,{gen_tcp,#Port<0.140371>,tls_connection,undefined},[<0.20406.17>,<0.20405.17>]}, 2, 131072, rabbit_framing_amqp_0_9_1, <0.20447.17>, {<<"client 10.188.34.37:6662 -> 20.122.170.159:5671">>,2}, false, 1000000000) at pid <0.20448.17>
2022-01-17 15:59:07.496 [debug] <0.20401.17> Shovel 'zzz' has finished setting up its topology

[michaelklishin]

Individual Shovels are entirely independent. What they do share is the underlying Erlang client, TLS library and URI/credential obfuscation library.

I don't think our team has the cycles to investigate issues like this. This is open source software, so you are welcome to do it if this makes any practical difference.

[michaelklishin]

IIRC months ago (3.8.16 is from May 2021) we addressed a couple of scenarios where shovels could affect each other's startup.
#3167, #3263, and another one involving credential obfuscation seed reuse come to mind.

The log contains virtual host access failures and one Shovel zzz restart which I cannot explain. So we don't have much specifics to work with.

Shovel is a small plugin with only a couple of modules responsible for its state machine. Searching the repo or GitHub for some
connection event log messages will lead you to the right place.

[inikulshin]

Maybe this is related to unexpected hostname_check_failed:

https://github.com/erlang/otp/blob/master/lib/ssl/src/ssl_certificate.erl

validate(Cert, valid_peer, UserState = #{role := client, server_name := Hostname, 
                                         customize_hostname_check := Customize}) when Hostname =/= disable ->
    case verify_hostname(Hostname, Customize, Cert, UserState) of
        {valid, UserState} ->
            validate(Cert, valid, UserState);
        Error ->
            Error
    end;

but in https://github.com/rabbitmq/rabbitmq-server/blob/master/deps/amqp_client/src/amqp_ssl.erl

% NOTE:
% The user state is the hostname to verify as configured in
% amqp_ssl:make_verify_fun
verify_fun(Cert, valid_peer, Hostname) when Hostname =/= disable ->
    verify_hostname(Cert, Hostname);

@michaelklishin are you sure UserState is hostname and not the record with server_name := Hostname?

[inikulshin]

@michaelklishin I'm not a SSL expert, but SNI and hostname check are similar, but different checks.

E.g. openssl s_client (https://www.openssl.org/docs/man1.1.1/man1/s_client.html) has

1. -verify_hostname hostname
2. -servername name

Imho, it is unexpected, that setting server_name_indication in shovel's URI affects hostname check.