base: fix child destruction while close requested

This patch fixes a corner case where a child is destructed while a
asynchronous close request to a sibling server is still pending.

The child immediately discarded the session ID as the end of the
close-session processing, assuming that this ID is never to be needed
again. The session-state continues to exist to handle asynchrous close
protocol with the server.

However, if the child is destructed at this point (before the server
responded to the session request), the destruction of the child would
not cover the discharging of the session state because the session state
was no longer be part of the client's ID space. So once the asynchronous
close response from the server came in, the session state contained
stale information, in particular a stale closed_callback pointer.

The patch fixes the problem by deferring the discarding of the client ID
to the point where the session state is actually destructed. So the
session of a pending close response is covered by the child destructor.

Thanks to Pirmin Duss for reporting this issue along with a test
scenario for reproducing it!

Fixes #4039

repos/base/src/lib/base/child.cc

@@ -467,7 +467,6 @@ Child::Close_result Child::_close(Session_state &session)
 
 	_policy.session_state_changed();
 
-	session.discard_id_at_client();
 	session.service().wakeup();
 
 	return CLOSE_PENDING;
@@ -926,7 +925,11 @@ void Child::close_all_sessions()
 	auto close_fn = [&] (Session_state &session) {
 		session.closed_callback = nullptr;
 		session.ready_callback  = nullptr;
-		(void)_close(session);
+
+		Close_result const close_result = _close(session);
+
+		if (close_result == CLOSE_PENDING)
+			session.discard_id_at_client();
 	};
 
 	while (_id_space.apply_any<Session_state>(close_fn));

repos/os/recipes/raw/test-init/test-init.config

@@ -1660,6 +1660,89 @@
 	<expect_warning string="[init] " colored="Warning: affinity-space configuration missing, but affinity defined for child: affinity"/>
 	<sleep ms="150"/>
 
+
+	<message string="destroy child while async close requested"/>
+
+	<!-- This is a regression test for issue #4039.
+	     A child is removed while a close request issued by the
+	     child is still pending. Once the close request is completed,
+	     the child can no longer be notified. -->
+
+	<init_config version="dangling_close">
+		<parent-provides>
+			<service name="ROM"/>
+			<service name="CPU"/>
+			<service name="PD"/>
+			<service name="LOG"/>
+			<service name="Timer"/>
+		</parent-provides>
+		<default caps="100"/>
+		<report requested="yes" provided="yes" delay_ms="100"/>
+		<start name="server">
+			<binary name="dummy"/>
+			<resource name="RAM" quantum="1M"/>
+			<provides> <service name="LOG"/> </provides>
+			<config> <log_service delay_close_ms="500"/> </config>
+			<route> <any-service> <parent/> </any-service> </route>
+		</start>
+		<start name="client">
+			<binary name="dummy"/>
+			<resource name="RAM" quantum="1M"/>
+			<config>
+				<log string="client started"/>
+				<create_log_connections count="1"/>
+				<log string="client created one log connection"/>
+				<destroy_log_connections/>
+				<log string="client destroyed log connection"/>
+			</config>
+			<route>
+				<service name="LOG" label_prefix=""> <child name="server"/> </service>
+				<any-service> <parent/> </any-service>
+			</route>
+		</start>
+	</init_config>
+	<sleep ms="300"/>
+	<expect_init_state>
+		<node name="child">
+			<attribute name="name" value="server"/>
+			<node name="provided">
+				<node name="session">
+					<attribute name="state" value="CLOSE_REQUESTED"/>
+				</node>
+			</node>
+		</node>
+	</expect_init_state>
+	<init_config version="dangling_close">
+		<parent-provides>
+			<service name="ROM"/>
+			<service name="CPU"/>
+			<service name="PD"/>
+			<service name="LOG"/>
+			<service name="Timer"/>
+		</parent-provides>
+		<default caps="100"/>
+		<report requested="yes" provided="yes" delay_ms="100"/>
+		<start name="server">
+			<binary name="dummy"/>
+			<resource name="RAM" quantum="1M"/>
+			<provides> <service name="LOG"/> </provides>
+			<config> <log_service delay_close_ms="500"/> </config>
+			<route> <any-service> <parent/> </any-service> </route>
+		</start>
+	</init_config>
+	<sleep ms="500"/>
+	<expect_init_state>
+		<node name="child">
+			<attribute name="name" value="server"/>
+			<node name="provided">
+				<not>
+					<node name="session"/>
+				</not>
+			</node>
+		</node>
+	</expect_init_state>
+	<sleep ms="150"/>
+
 	<message string="test complete"/>
 
 </config>

repos/os/src/app/dummy/main.cc

@@ -39,25 +39,31 @@ struct Dummy::Log_service
 
 	Sliced_heap _heap { _env.ram(), _env.rm() };
 
-	bool const _verbose;
+	struct Args
+	{
+		bool     verbose;
+		unsigned delay_close_ms;
+	};
+
+	Args const _args;
 
 	struct Session_component : Rpc_object<Log_session>
 	{
 		Session_label const _label;
 
-		bool const _verbose;
+		Args const _args;
 
-		Session_component(Session_label const &label, bool verbose)
+		Session_component(Session_label const &label, Args args)
 		:
-			_label(label), _verbose(verbose)
+			_label(label), _args(args)
 		{
-			if (_verbose)
+			if (_args.verbose)
 				log("opening session with label ", _label);
 		}
 
 		~Session_component()
 		{
-			if (_verbose)
+			if (_args.verbose)
 				log("closing session with label ", _label);
 		}
 
@@ -78,16 +84,22 @@ struct Dummy::Log_service
 	{
 		Pd_session &_pd;
 
-		bool const _verbose;
+		Log_service::Args const _service_args;
 
-		Root(Entrypoint &ep, Allocator &alloc, Pd_session &pd, bool verbose)
+		Constructible<Timer::Connection> _timer { };
+
+		Root(Env &env, Allocator &alloc, Pd_session &pd, Log_service::Args args)
 		:
-			Root_component(ep, alloc), _pd(pd), _verbose(verbose)
+			Root_component(env.ep(), alloc), _pd(pd), _service_args(args)
-		{ }
+		{
+			if (args.delay_close_ms)
+				_timer.construct(env);
+		}
 
 		Session_component *_create_session(const char *args, Affinity const &) override
 		{
-			return new (md_alloc()) Session_component(label_from_args(args), _verbose);
+			return new (md_alloc())
+				Session_component(label_from_args(args), _service_args);
 		}
 
 		void _upgrade_session(Session_component *, const char *args) override
@@ -98,11 +110,25 @@ struct Dummy::Log_service
 			if (_pd.avail_ram().value >= ram_quota)
 				log("received session quota upgrade");
 		}
+
+		void _destroy_session(Session_component *session) override
+		{
+			if (_timer.constructed()) {
+				log("delay close by ", _service_args.delay_close_ms, " ms");
+				_timer->msleep(_service_args.delay_close_ms);
+			}
+			else
+			{
+				log("close session without delay");
+			}
+
+			Root_component::_destroy_session(session);
+		}
 	};
 
-	Root _root { _env.ep(), _heap, _env.pd(), _verbose };
+	Root _root { _env, _heap, _env.pd(), _args };
 
-	Log_service(Env &env, bool verbose) : _env(env), _verbose(verbose)
+	Log_service(Env &env, Args args) : _env(env), _args(args)
 	{
 		_env.parent().announce(_env.ep().manage(_root));
 		log("created LOG service");
@@ -311,7 +337,10 @@ struct Dummy::Main
 				_log_connections.destruct();
 
 			if (node.type() == "log_service")
-				_log_service.construct(_env, node.attribute_value("verbose", false));
+				_log_service.construct(_env, Log_service::Args {
+					.verbose        = node.attribute_value("verbose", false),
+					.delay_close_ms = node.attribute_value("delay_close_ms", 0U)
+				});
 
 			if (node.type() == "consume_ram")
 				_ram_consumer.consume(node.attribute_value("amount", Number_of_bytes()));