run/nic_router_dhcp: DHCP RENEW and some fixes

* Test DHCP RENEW by the test client in the unmanaged variant.
* Add event IDs to log output of test client in order to prevent false positive
  result in the managed variant.
* Let managed and unmanaged variant have separate string patterns for
  'run_genode_until' because they already had different output and it will
  differ even more as we don't want to test DHCP RENEW with the managed
  variant.
* Delay first test client DHCP in order to fix unexpected sporadic initial IP
  config.
* Remove some unnecessary code from the run script

Fixes #4460

repos/os/run/nic_router_dhcp.inc

@@ -94,10 +94,10 @@ append config {
 					</config>
 
 				</inline>
-				<sleep milliseconds="2000"/>
+				<sleep milliseconds="4000"/>
 				<inline>
 
-					<config verbose="yes">
+					<config>
 
 						<policy label="nic_router_2 -> " domain="downlink"/>
 
@@ -199,6 +199,7 @@ append_if [expr ![nic_router_2_managed]] config {
 
 				<dhcp-server ip_first="10.0.3.2"
 				             ip_last="10.0.3.2"
+				             ip_lease_time_sec="6"
 				             dns_config_from="uplink"/>
 
 			</domain>
@@ -280,7 +281,9 @@ build_boot_image $boot_modules
 append qemu_args " -nographic "
 append_qemu_nic_args
 
-append done_string ".*DHCP request completed:.*\n"
+if {[nic_router_2_managed]} {
+
+append done_string ".*Event 1, DHCP request completed:.*\n"
 append done_string ".*  IP lease time: 3600 seconds.*\n"
 append done_string ".*  Interface: 10.0.3.2/24.*\n"
 append done_string ".*  Router: 10.0.3.1.*\n"
@@ -288,28 +291,23 @@ append done_string ".*  DNS server #1: 1.2.3.4.*\n"
 append done_string ".*  DNS server #2: 2.3.4.5.*\n"
 append done_string ".*  DNS server #3: 3.4.5.6.*\n"
 append done_string ".*  DNS domain name: genode.org.*\n"
-append done_string ".*DHCP request completed:.*\n"
+append done_string ".*Event 2, DHCP request completed:.*\n"
 append done_string ".*  IP lease time: 3600 seconds.*\n"
 append done_string ".*  Interface: 10.0.3.2/24.*\n"
 append done_string ".*  Router: 10.0.3.1.*\n"
 append done_string ".*  DNS server #1: 4.5.6.7.*\n"
 append done_string ".*  DNS server #2: 5.6.7.8.*\n"
-append done_string ".*DHCP request completed:.*\n"
+append done_string ".*Event 3, DHCP request completed:.*\n"
 append done_string ".*  IP lease time: 3600 seconds.*\n"
 append done_string ".*  Interface: 10.0.3.2/24.*\n"
 append done_string ".*  Router: 10.0.3.1.*\n"
 append done_string ".*  DNS server #1: 6.7.8.9.*\n"
-append done_string ".*DHCP request completed:.*\n"
+append done_string ".*Event 4, DHCP request completed:.*\n"
 append done_string ".*  IP lease time: 3600 seconds.*\n"
 append done_string ".*  Interface: 10.0.3.2/24.*\n"
 append done_string ".*  Router: 10.0.3.1.*\n"
 append done_string ".*  DNS domain name: genodians.org.*\n"
-append done_string ".*DHCP request completed:.*\n"
+append done_string ".*Event 5, DHCP request completed:.*\n"
-append done_string ".*  IP lease time: 3600 seconds.*\n"
-append done_string ".*  Interface: 10.0.3.2/24.*\n"
-append done_string ".*  Router: 10.0.3.1.*\n"
-append done_string ".*  DNS domain name: genodians.org.*\n"
-append done_string ".*DHCP request completed:.*\n"
 append done_string ".*  IP lease time: 3600 seconds.*\n"
 append done_string ".*  Interface: 10.0.3.2/24.*\n"
 append done_string ".*  Router: 10.0.3.1.*\n"
@@ -318,4 +316,52 @@ append done_string ".*  DNS server #2: 2.3.4.5.*\n"
 append done_string ".*  DNS server #3: 3.4.5.6.*\n"
 append done_string ".*  DNS domain name: genode.org.*\n"
 
+} else {
+
+append done_string ".*Event 1, DHCP request completed:.*\n"
+append done_string ".*  IP lease time: 6 seconds.*\n"
+append done_string ".*  Interface: 10.0.3.2/24.*\n"
+append done_string ".*  Router: 10.0.3.1.*\n"
+append done_string ".*  DNS server #1: 1.2.3.4.*\n"
+append done_string ".*  DNS server #2: 2.3.4.5.*\n"
+append done_string ".*  DNS server #3: 3.4.5.6.*\n"
+append done_string ".*  DNS domain name: genode.org.*\n"
+append done_string ".*Event 2, DHCP request completed:.*\n"
+append done_string ".*  IP lease time: 6 seconds.*\n"
+append done_string ".*  Interface: 10.0.3.2/24.*\n"
+append done_string ".*  Router: 10.0.3.1.*\n"
+append done_string ".*  DNS server #1: 4.5.6.7.*\n"
+append done_string ".*  DNS server #2: 5.6.7.8.*\n"
+append done_string ".*Event 3, DHCP renew completed:.*\n"
+append done_string ".*  IP lease time: 6 seconds.*\n"
+append done_string ".*  Interface: 10.0.3.2/24.*\n"
+append done_string ".*  Router: 10.0.3.1.*\n"
+append done_string ".*  DNS server #1: 4.5.6.7.*\n"
+append done_string ".*  DNS server #2: 5.6.7.8.*\n"
+append done_string ".*Event 4, DHCP request completed:.*\n"
+append done_string ".*  IP lease time: 6 seconds.*\n"
+append done_string ".*  Interface: 10.0.3.2/24.*\n"
+append done_string ".*  Router: 10.0.3.1.*\n"
+append done_string ".*  DNS server #1: 6.7.8.9.*\n"
+append done_string ".*Event 5, DHCP request completed:.*\n"
+append done_string ".*  IP lease time: 6 seconds.*\n"
+append done_string ".*  Interface: 10.0.3.2/24.*\n"
+append done_string ".*  Router: 10.0.3.1.*\n"
+append done_string ".*  DNS domain name: genodians.org.*\n"
+append done_string ".*Event 6, DHCP request completed:.*\n"
+append done_string ".*  IP lease time: 6 seconds.*\n"
+append done_string ".*  Interface: 10.0.3.2/24.*\n"
+append done_string ".*  Router: 10.0.3.1.*\n"
+append done_string ".*  DNS domain name: genodians.org.*\n"
+append done_string ".*Event 7, DHCP request completed:.*\n"
+append done_string ".*  IP lease time: 6 seconds.*\n"
+append done_string ".*  Interface: 10.0.3.2/24.*\n"
+append done_string ".*  Router: 10.0.3.1.*\n"
+append done_string ".*  DNS server #1: 1.2.3.4.*\n"
+append done_string ".*  DNS server #2: 2.3.4.5.*\n"
+append done_string ".*  DNS server #3: 3.4.5.6.*\n"
+append done_string ".*  DNS domain name: genode.org.*\n"
+
+}
+
 run_genode_until $done_string 30

repos/os/src/test/nic_router_dhcp/client/dhcp_client.cc

@@ -75,6 +75,7 @@ void Dhcp_client::_discover()
 
 void Dhcp_client::_rerequest(State next_state)
 {
+	_handler.ip_config(Ipv4_config { });
 	_set_state(next_state, _rerequest_timeout(2));
 	Ipv4_address const client_ip = _handler.ip_config().interface.address;
 	_send(Message_type::REQUEST, client_ip, Ipv4_address(), client_ip);
@@ -91,14 +92,14 @@ void Dhcp_client::_set_state(State state, Microseconds timeout)
 Microseconds Dhcp_client::_rerequest_timeout(unsigned lease_time_div_log2)
 {
 	/* FIXME limit the time because of shortcomings in timeout framework */
-	enum { MAX_TIMEOUT_SEC = 3600 };
+	enum : uint64_t { MAX_TIMEOUT_US = (uint64_t)3600 * 1000 * 1000 };
-	uint64_t timeout_sec = _lease_time_sec >> lease_time_div_log2;
+	uint64_t timeout_us = (_lease_time_sec * 1000 * 1000) >> lease_time_div_log2;
 
-	if (timeout_sec > MAX_TIMEOUT_SEC) {
+	if (timeout_us > MAX_TIMEOUT_US) {
-		timeout_sec = MAX_TIMEOUT_SEC;
+		timeout_us = MAX_TIMEOUT_US;
 		warning("Had to prune the state timeout of DHCP client");
 	}
-	return Microseconds(timeout_sec * 1000 * 1000);
+	return Microseconds(timeout_us);
 }
 
 
@@ -140,24 +141,10 @@ void Dhcp_client::handle_eth(Ethernet_frame &eth, Size_guard &size_guard)
 }
 
 
-void Dhcp_client::_handle_dhcp_reply(Dhcp_packet &dhcp)
+void
-{
+Dhcp_client::_handle_dhcp_reply_in_request_state(Message_type  msg_type,
-	Message_type const msg_type =
+                                                 Dhcp_packet  &dhcp,
-		dhcp.option<Dhcp_packet::Message_type_option>().value();
+                                                 char const   *request_state)
-
-	switch (_state) {
-	case State::SELECT:
-
-		if (msg_type != Message_type::OFFER) {
-			throw Drop_packet_inform("DHCP client expects an offer");
-		}
-		_set_state(State::REQUEST, _request_timeout);
-		_send(Message_type::REQUEST, Ipv4_address(),
-		      dhcp.option<Dhcp_packet::Server_ipv4>().value(),
-		      dhcp.yiaddr());
-		break;
-
-	case State::REQUEST:
 {
 	if (msg_type != Message_type::ACK) {
 		throw Drop_packet_inform("DHCP client expects an acknowledgement");
@@ -165,7 +152,8 @@ void Dhcp_client::_handle_dhcp_reply(Dhcp_packet &dhcp)
 	_lease_time_sec = dhcp.option<Dhcp_packet::Ip_lease_time>().value();
 	_set_state(State::BOUND, _rerequest_timeout(1));
 
-			log("DHCP request completed:");
+	static unsigned long event_idx { 0 };
+	log("Event ", ++event_idx, ", DHCP ", request_state, " completed:");
 	log("  IP lease time: ", _lease_time_sec, " seconds");
 	log("  Interface: ", Ipv4_address_prefix(dhcp.yiaddr(), dhcp.option<Dhcp_packet::Subnet_mask>().value()));
 	log("  Router: ", dhcp.option<Dhcp_packet::Router_ipv4>().value());
@@ -203,18 +191,29 @@ void Dhcp_client::_handle_dhcp_reply(Dhcp_packet &dhcp)
 		dns_server_addr);
 
 	_handler.ip_config(ip_config);
-			break;
 }
-	case State::RENEW:
-	case State::REBIND:
 
-		if (msg_type != Message_type::ACK) {
+
-			throw Drop_packet_inform("DHCP client expects an acknowledgement");
+void Dhcp_client::_handle_dhcp_reply(Dhcp_packet &dhcp)
+{
+	Message_type const msg_type =
+		dhcp.option<Dhcp_packet::Message_type_option>().value();
+
+	switch (_state) {
+	case State::SELECT:
+
+		if (msg_type != Message_type::OFFER) {
+			throw Drop_packet_inform("DHCP client expects an offer");
 		}
-		_set_state(State::BOUND, _rerequest_timeout(1));
+		_set_state(State::REQUEST, _request_timeout);
-		_lease_time_sec = dhcp.option<Dhcp_packet::Ip_lease_time>().value();
+		_send(Message_type::REQUEST, Ipv4_address(),
+		      dhcp.option<Dhcp_packet::Server_ipv4>().value(),
+		      dhcp.yiaddr());
 		break;
 
+	case State::REQUEST: _handle_dhcp_reply_in_request_state(msg_type, dhcp, "request"); break;
+	case State::RENEW:   _handle_dhcp_reply_in_request_state(msg_type, dhcp, "renew");   break;
+	case State::REBIND:  _handle_dhcp_reply_in_request_state(msg_type, dhcp, "rebind");  break;
 	default: throw Drop_packet_inform("DHCP client doesn't expect a packet");
 	}
 }

repos/os/src/test/nic_router_dhcp/client/dhcp_client.h

@@ -73,6 +73,11 @@ class Net::Dhcp_client
 		Nic                                  &_nic;
 		Dhcp_client_handler                  &_handler;
 
+		void
+		_handle_dhcp_reply_in_request_state(Dhcp_packet::Message_type  msg_type,
+		                                    Dhcp_packet               &dhcp,
+		                                    char const                *request_state);
+
 		void _handle_dhcp_reply(Dhcp_packet &dhcp);
 
 		void _handle_timeout(Genode::Duration);

repos/os/src/test/nic_router_dhcp/client/main.cc

@@ -42,6 +42,9 @@ class Main : public Nic_handler,
 		Constructible<Dhcp_client>      _dhcp_client        { };
 		bool                            _link_state         { false };
 		Reconstructible<Ipv4_config>    _ip_config          { };
+		Timer::One_shot_timeout<Main>   _initial_delay      { _timer, *this, &Main::_handle_initial_delay };
+
+		void _handle_initial_delay(Duration);
 
 	public:
 
@@ -88,13 +91,19 @@ void Main::ip_config(Ipv4_config const &ip_config)
 }
 
 
-Main::Main(Env &env) : _env(env)
+void Main::_handle_initial_delay(Duration)
 {
 	log("Initialized");
 	_nic.handle_link_state();
 }
 
 
+Main::Main(Env &env) : _env(env)
+{
+	_initial_delay.schedule(Microseconds { 1000000 });
+}
+
+
 void Main::handle_eth(Ethernet_frame &eth,
                       Size_guard     &size_guard)
 {