[BUG] Un-closed transports while starting up minion

[dwoz]

Description

If a master is mis-behaving it may cause and exception which can leave the minion with un-closed transports.

 File "/usr/bin/salt-minion", line 11, in <module>
   sys.exit(salt_minion())
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 214, in salt_minion
   process.start()
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/process.py", line 121, in start
   self._popen = self._Popen(self)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/context.py", line 224, in _Popen
   return _default_context.get_context().Process._Popen(process_obj)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/context.py", line 281, in _Popen
   return Popen(process_obj)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/popen_fork.py", line 19, in __init__
   self._launch(process_obj)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/popen_fork.py", line 71, in _launch
   code = process_obj._bootstrap(parent_sentinel=child_r)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/process.py", line 314, in _bootstrap
   self.run()
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/process.py", line 108, in run
   self._target(*self._args, **self._kwargs)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 142, in minion_process
   minion.start()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/daemons.py", line 325, in start
   self._real_start()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/daemons.py", line 337, in _real_start
   self.minion.tune_in()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 1221, in tune_in
   self.io_loop.start()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/ioloop.py", line 834, in start
   self._run_callback(self._callbacks.popleft())
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/ioloop.py", line 606, in _run_callback
   ret = callback()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/stack_context.py", line 278, in null_wrapper
   return fn(*args, **kwargs)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1153, in inner
   self.run()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1070, in run
   yielded = self.gen.send(value)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 1174, in _connect_minion
   yield minion.connect_master(failed=failed)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 309, in wrapper
   yielded = next(result)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 1400, in connect_master
   master, self.pub_channel = yield self.eval_master(
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 309, in wrapper
   yielded = next(result)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 842, in eval_master
   pub_channel = salt.channel.client.AsyncPubChannel.factory(
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/channel/client.py", line 407, in factory
   transport = salt.transport.publish_client(opts, io_loop)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py", line 92, in publish_client
   return salt.transport.zeromq.PublishClient(opts, io_loop)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/zeromq.py", line 112, in __init__
   super().__init__(opts, io_loop, **kwargs)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py", line 247, in __init__
   super().__init__()
 warnings.warn(
TransportWarning: Enable tracemalloc to get the object allocation traceback
/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py:129: TransportWarning: Unclosed transport! <salt.transport.zeromq.RequestClient object at 0x7f72903dc5e0>



 File "/usr/bin/salt-minion", line 11, in <module>
   sys.exit(salt_minion())
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 214, in salt_minion
   process.start()
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/process.py", line 121, in start
   self._popen = self._Popen(self)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/context.py", line 224, in _Popen
   return _default_context.get_context().Process._Popen(process_obj)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/context.py", line 281, in _Popen
   return Popen(process_obj)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/popen_fork.py", line 19, in __init__
   self._launch(process_obj)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/popen_fork.py", line 71, in _launch
   code = process_obj._bootstrap(parent_sentinel=child_r)
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/process.py", line 314, in _bootstrap
   self.run()
 File "/opt/saltstack/salt/lib/python3.10/multiprocessing/process.py", line 108, in run
   self._target(*self._args, **self._kwargs)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 142, in minion_process
   minion.start()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/daemons.py", line 325, in start
   self._real_start()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/daemons.py", line 337, in _real_start
   self.minion.tune_in()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 1221, in tune_in
   self.io_loop.start()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/ioloop.py", line 834, in start
   self._run_callback(self._callbacks.popleft())
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/ioloop.py", line 606, in _run_callback
   ret = callback()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/stack_context.py", line 278, in null_wrapper
   return fn(*args, **kwargs)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1153, in inner
   self.run()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1070, in run
   yielded = self.gen.send(value)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 1174, in _connect_minion
   yield minion.connect_master(failed=failed)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 321, in wrapper
   _futures_to_runners[future] = Runner(result, future, yielded)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1004, in __init__
   self.run()
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1070, in run
   yielded = self.gen.send(value)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 1405, in connect_master
   self.req_channel = salt.channel.client.AsyncReqChannel.factory(
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/channel/client.py", line 137, in factory
   transport = salt.transport.request_client(opts, io_loop=io_loop)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py", line 47, in request_client
   return salt.transport.zeromq.RequestClient(opts, io_loop=io_loop)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/zeromq.py", line 890, in __init__
   super().__init__(opts, io_loop)
 File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py", line 145, in __init__
   super().__init__()
 warnings.warn(
TransportWarning: Enable tracemalloc to get the object allocation traceback

Versions Report

This was observed on 3006.5

[doesitblend]

@dwoz Can clarify what constitutes a "master misbehaving" in this case? Do you just mean a master that is very busy and maybe not keeping up with workload?

[jheiselman]

Does this have to do with #61565 ?

[dwoz]

@doesitblend The master in question here was not overloaded but something was wrong with it's network causing minions to continually re-connect. At least, that was my understanding.

[dwoz]

This went into 3006.7

[wibbit]

Morning all, I'm seeing this exact same error, but with salt 3006.9.

Sep 11 11:33:28 server-syndic salt-syndic[2504609]: [CRITICAL] Unable to call _fire_master on any masters!
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: /opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py:129: TransportWarning: Unclosed transport! <salt.transport.zeromq.RequestClient object at 0x7f3bbb034820>
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/usr/bin/salt-syndic", line 11, in
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: sys.exit(salt_syndic())
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 402, in salt_syndic
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: syndic.start()
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/daemons.py", line 600, in start
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: self.syndic.tune_in()
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 3697, in tune_in
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: self.io_loop.start()
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/ioloop.py", line 834, in start
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: self._run_callback(self._callbacks.popleft())
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/ioloop.py", line 606, in _run_callback
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: ret = callback()
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/stack_context.py", line 278, in null_wrapper
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: return fn(*args, **kwargs)
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1153, in inner
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: self.run()
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/ext/tornado/gen.py", line 1070, in run
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: yielded = self.gen.send(value)
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/minion.py", line 1394, in connect_master
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: self.req_channel = salt.channel.client.AsyncReqChannel.factory(
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/channel/client.py", line 121, in factory
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: transport = salt.transport.request_client(opts, io_loop=io_loop)
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py", line 47, in request_client
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: return salt.transport.zeromq.RequestClient(opts, io_loop=io_loop)
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/zeromq.py", line 904, in init
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: super().init(opts, io_loop)
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/transport/base.py", line 145, in init
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: super().init()
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: warnings.warn(
Sep 11 11:33:30 server-syndic salt-syndic[2504609]: TransportWarning: Enable tracemalloc to get the object allocation traceback

Salt MoM & Syndics both running 3006.9

[wibbit]

I can't seem to edit my posts, it's not quite the same stack trace, but the error does appear to be very similar.