Hi, On Thu, Jul 12, 2012 at 09:58:52AM -0400, Forest Bond wrote: > On Thu, Jul 05, 2012 at 03:55:53PM -0400, Forest Bond wrote: > > On Wed, Jul 04, 2012 at 02:58:24PM +0200, Daniel Wagner wrote: > > > On 03.07.2012 20:12, Forest Bond wrote: > > > >On Tue, Jul 03, 2012 at 08:56:37AM -0300, Paulo Pizarro wrote: > > > >>I'm having a similar problem using the ethernet interface with a Cisco > > > >>switch. > > > >>I picked up the packets with tcpdump and noticed that the switch > > > >>discards all packets sent by the "connman." > > > >>The Switch is attempting to discover the network topology by > > > >>performing the algorithm "spanning tree". > > > >>And while this procedure does not end it drops all packets. > > > >>The total time can be 30 seconds if it uses the algorithm "rapid > > > >>spanning tree", or it may take 60 seconds if it uses the "spanning > > > >>tree". > > > >> > > > >>I'm using version 1.2. > > > > > > > >I don't think this is related. In my case we are able to get a lease, > > > >we just > > > >aren't able to renew or replace it when it expires. But thanks for the > > > >info. > > > > > > Well, we could do a quick test. Can update the gdhcp sub directory? > > > That should be quite easy to do. > > > > Okay, fair enough. Let me see what I can arrange. > > Alright, this is the same version of ConnMan with gdhcp from recent git: > > > Jul 11 02:02:35 platform connmand[719]: DHCP: switch listening mode (0 ==> 1) > Jul 11 02:02:35 platform connmand[719]: DHCP: sending DHCP discover request > > Jul 11 02:02:36 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 0) > Jul 11 02:02:36 platform connmand[719]: DHCP: start request (retries 0) > Jul 11 02:02:36 platform connmand[719]: DHCP: sending DHCP select request > Jul 11 02:02:36 platform connmand[719]: DHCP: received DHCP packet with > message type 5 (current state 1) > Jul 11 02:02:36 platform connmand[719]: DHCP: switch listening mode (1 ==> 0) > Jul 11 02:02:36 platform connmand[719]: DHCP: start bound > Jul 11 02:02:36 platform connmand[719]: DHCP: processed DHCP packet (new > state 2) > > Jul 11 02:02:40 platform connmand[719]: DHCP: sending DHCP release request > Jul 11 02:02:40 platform connmand[719]: DHCP: switch listening mode (0 ==> 1) > > Jul 11 02:02:41 platform connmand[719]: DHCP: sending DHCP discover request > Jul 11 02:02:41 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 0) > Jul 11 02:02:41 platform connmand[719]: DHCP: start request (retries 0) > Jul 11 02:02:41 platform connmand[719]: DHCP: sending DHCP select request > Jul 11 02:02:41 platform connmand[719]: DHCP: received DHCP packet with > message type 5 (current state 1) > Jul 11 02:02:41 platform connmand[719]: DHCP: switch listening mode (1 ==> 0) > Jul 11 02:02:41 platform connmand[719]: DHCP: start bound > Jul 11 02:02:41 platform connmand[719]: DHCP: processed DHCP packet (new > state 2) > > Jul 11 14:02:42 platform connmand[719]: DHCP: start renew timeout > Jul 11 14:02:42 platform connmand[719]: DHCP: switch listening mode (0 ==> 2) > Jul 11 14:02:42 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 11 20:02:42 platform connmand[719]: DHCP: start renew timeout > Jul 11 20:02:42 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 11 23:02:42 platform connmand[719]: DHCP: start renew timeout > Jul 11 23:02:42 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 00:32:42 platform connmand[719]: DHCP: start renew timeout > Jul 12 00:32:42 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 01:17:42 platform connmand[719]: DHCP: start renew timeout > Jul 12 01:17:42 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 01:40:12 platform connmand[719]: DHCP: start renew timeout > Jul 12 01:40:12 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 01:51:27 platform connmand[719]: DHCP: start renew timeout > Jul 12 01:51:27 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 01:57:04 platform connmand[719]: DHCP: start renew timeout > Jul 12 01:57:04 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 01:59:52 platform connmand[719]: DHCP: start renew timeout > Jul 12 01:59:52 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 02:01:16 platform connmand[719]: DHCP: start renew timeout > Jul 12 02:01:16 platform connmand[719]: DHCP: sending DHCP renew request > > Jul 12 02:01:58 platform connmand[719]: DHCP: start renew timeout > Jul 12 02:01:58 platform connmand[719]: DHCP: start rebound > > Jul 12 02:02:19 platform connmand[719]: DHCP: start rebound timeout > Jul 12 02:02:19 platform connmand[719]: DHCP: switch listening mode (2 ==> 1) > Jul 12 02:02:19 platform connmand[719]: DHCP: sending DHCP rebound request > Jul 12 02:02:19 platform connmand[719]: DHCP: received DHCP packet with > message type 6 (current state 4) > Jul 12 02:02:19 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:22 platform connmand[719]: DHCP: restart DHCP timeout > Jul 12 02:02:22 platform connmand[719]: DHCP: restart DHCP (retries 1) > Jul 12 02:02:22 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:22 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:22 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:25 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:25 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:25 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:28 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:28 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:28 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:31 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:31 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:31 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:34 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:34 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:34 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:37 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:37 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:37 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:40 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:40 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:40 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:43 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:43 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:43 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:46 platform connmand[719]: DHCP: sending DHCP discover request > Jul 12 02:02:46 platform connmand[719]: DHCP: received DHCP packet with > message type 2 (current state 4) > Jul 12 02:02:46 platform connmand[719]: DHCP: processed DHCP packet (new > state 4) > > Jul 12 02:02:49 platform connmand[719]: DHCP: switch listening mode (1 ==> 0) > Jul 12 02:02:49 platform connmand[719]: DHCP: sending IPV4LL probe request > Jul 12 02:02:49 platform connmand[719]: DHCP: switch listening mode (0 ==> 3) > Jul 12 02:02:51 platform connmand[719]: DHCP: IPV4LL probe timeout (retries 1) > Jul 12 02:02:51 platform connmand[719]: DHCP: sending IPV4LL probe request > Jul 12 02:02:53 platform connmand[719]: DHCP: IPV4LL probe timeout (retries 2) > Jul 12 02:02:53 platform connmand[719]: DHCP: sending IPV4LL probe request > Jul 12 02:02:55 platform connmand[719]: DHCP: IPV4LL probe timeout (retries 3) > Jul 12 02:02:55 platform connmand[719]: DHCP: sending IPV4LL announce request > Jul 12 02:02:58 platform connmand[719]: DHCP: request timeout (retries 1) > Jul 12 02:02:58 platform connmand[719]: DHCP: sending IPV4LL announce request > Jul 12 02:03:00 platform connmand[719]: DHCP: request timeout (retries 2) > Jul 12 02:03:00 platform connmand[719]: DHCP: switching to monitor mode > > > Looks like the same issue. If my original analysis was correct, the following > would probably fix the problem: > > > diff --git a/gdhcp/client.c b/gdhcp/client.c > index ec1b2a2..7280e1d 100644 > --- a/gdhcp/client.c > +++ b/gdhcp/client.c > @@ -1361,6 +1361,7 @@ static void restart_dhcp(GDHCPClient *dhcp_client, int > retry_times) > > dhcp_client->retry_times = retry_times; > dhcp_client->requested_ip = 0; > + dhcp_client->state = INIT_SELECTING; > switch_listening_mode(dhcp_client, L2); > > g_dhcp_client_start(dhcp_client, dhcp_client->last_address);
Well, I decided to go ahead and test this fix and it does appear to do the right
thing:
Jul 13 19:18:07 platform connmand[692]: DHCP: switch listening mode (0 ==> 1)
Jul 13 19:18:07 platform connmand[692]: DHCP: sending DHCP discover request
Jul 13 19:18:08 platform connmand[692]: DHCP: received DHCP packet with message
type 2 (current state 0)
Jul 13 19:18:08 platform connmand[692]: DHCP: start request (retries 0)
Jul 13 19:18:08 platform connmand[692]: DHCP: sending DHCP select request
Jul 13 19:18:08 platform connmand[692]: DHCP: received DHCP packet with message
type 5 (current state 1)
Jul 13 19:18:08 platform connmand[692]: DHCP: switch listening mode (1 ==> 0)
Jul 13 19:18:08 platform connmand[692]: DHCP: start bound
Jul 13 19:18:08 platform connmand[692]: DHCP: processed DHCP packet (new state
2)
Jul 13 19:18:12 platform connmand[692]: DHCP: sending DHCP release request
Jul 13 19:18:12 platform connmand[692]: DHCP: switch listening mode (0 ==> 1)
Jul 13 19:18:12 platform connmand[692]: DHCP: sending DHCP discover request
Jul 13 19:18:13 platform connmand[692]: DHCP: received DHCP packet with message
type 2 (current state 0)
Jul 13 19:18:13 platform connmand[692]: DHCP: start request (retries 0)
Jul 13 19:18:13 platform connmand[692]: DHCP: sending DHCP select request
Jul 13 19:18:13 platform connmand[692]: DHCP: received DHCP packet with message
type 5 (current state 1)
Jul 13 19:18:13 platform connmand[692]: DHCP: switch listening mode (1 ==> 0)
Jul 13 19:18:13 platform connmand[692]: DHCP: start bound
Jul 13 19:18:13 platform connmand[692]: DHCP: processed DHCP packet (new state
2)
Jul 13 19:19:05 platform connmand[698]: DHCP: switch listening mode (0 ==> 1)
Jul 13 19:19:05 platform connmand[698]: DHCP: sending DHCP discover request
Jul 13 19:19:06 platform connmand[698]: DHCP: received DHCP packet with message
type 2 (current state 0)
Jul 13 19:19:06 platform connmand[698]: DHCP: start request (retries 0)
Jul 13 19:19:06 platform connmand[698]: DHCP: sending DHCP select request
Jul 13 19:19:06 platform connmand[698]: DHCP: received DHCP packet with message
type 5 (current state 1)
Jul 13 19:19:06 platform connmand[698]: DHCP: switch listening mode (1 ==> 0)
Jul 13 19:19:06 platform connmand[698]: DHCP: start bound
Jul 13 19:19:06 platform connmand[698]: DHCP: processed DHCP packet (new state
2)
Jul 13 19:19:10 platform connmand[698]: DHCP: sending DHCP release request
Jul 13 19:19:10 platform connmand[698]: DHCP: switch listening mode (0 ==> 1)
Jul 13 19:19:10 platform connmand[698]: DHCP: sending DHCP discover request
Jul 13 19:19:11 platform connmand[698]: DHCP: received DHCP packet with message
type 2 (current state 0)
Jul 13 19:19:11 platform connmand[698]: DHCP: start request (retries 0)
Jul 13 19:19:11 platform connmand[698]: DHCP: sending DHCP select request
Jul 13 19:19:11 platform connmand[698]: DHCP: received DHCP packet with message
type 5 (current state 1)
Jul 13 19:19:11 platform connmand[698]: DHCP: switch listening mode (1 ==> 0)
Jul 13 19:19:11 platform connmand[698]: DHCP: start bound
Jul 13 19:19:11 platform connmand[698]: DHCP: processed DHCP packet (new state
2)
Jul 13 19:20:03 platform connmand[701]: DHCP: switch listening mode (0 ==> 1)
Jul 13 19:20:03 platform connmand[701]: DHCP: sending DHCP discover request
Jul 13 19:20:04 platform connmand[701]: DHCP: received DHCP packet with message
type 2 (current state 0)
Jul 13 19:20:04 platform connmand[701]: DHCP: start request (retries 0)
Jul 13 19:20:04 platform connmand[701]: DHCP: sending DHCP select request
Jul 13 19:20:04 platform connmand[701]: DHCP: received DHCP packet with message
type 5 (current state 1)
Jul 13 19:20:04 platform connmand[701]: DHCP: switch listening mode (1 ==> 0)
Jul 13 19:20:04 platform connmand[701]: DHCP: start bound
Jul 13 19:20:04 platform connmand[701]: DHCP: processed DHCP packet (new state
2)
Jul 13 19:20:08 platform connmand[701]: DHCP: sending DHCP release request
Jul 13 19:20:08 platform connmand[701]: DHCP: switch listening mode (0 ==> 1)
Jul 13 19:20:08 platform connmand[701]: DHCP: sending DHCP discover request
Jul 13 19:20:09 platform connmand[701]: DHCP: received DHCP packet with message
type 2 (current state 0)
Jul 13 19:20:09 platform connmand[701]: DHCP: start request (retries 0)
Jul 13 19:20:09 platform connmand[701]: DHCP: sending DHCP select request
Jul 13 19:20:09 platform connmand[701]: DHCP: received DHCP packet with message
type 5 (current state 1)
Jul 13 19:20:09 platform connmand[701]: DHCP: switch listening mode (1 ==> 0)
Jul 13 19:20:09 platform connmand[701]: DHCP: start bound
Jul 13 19:20:09 platform connmand[701]: DHCP: processed DHCP packet (new state
2)
Jul 14 07:20:10 platform connmand[701]: DHCP: start renew timeout
Jul 14 07:20:10 platform connmand[701]: DHCP: switch listening mode (0 ==> 2)
Jul 14 07:20:10 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 13:20:10 platform connmand[701]: DHCP: start renew timeout
Jul 14 13:20:10 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 16:20:10 platform connmand[701]: DHCP: start renew timeout
Jul 14 16:20:10 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 17:50:10 platform connmand[701]: DHCP: start renew timeout
Jul 14 17:50:10 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 18:35:10 platform connmand[701]: DHCP: start renew timeout
Jul 14 18:35:10 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 18:57:40 platform connmand[701]: DHCP: start renew timeout
Jul 14 18:57:40 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 19:08:55 platform connmand[701]: DHCP: start renew timeout
Jul 14 19:08:55 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 19:14:32 platform connmand[701]: DHCP: start renew timeout
Jul 14 19:14:32 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 19:17:20 platform connmand[701]: DHCP: start renew timeout
Jul 14 19:17:20 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 19:18:44 platform connmand[701]: DHCP: start renew timeout
Jul 14 19:18:44 platform connmand[701]: DHCP: sending DHCP renew request
Jul 14 19:19:26 platform connmand[701]: DHCP: start renew timeout
Jul 14 19:19:26 platform connmand[701]: DHCP: start rebound
Jul 14 19:19:47 platform connmand[701]: DHCP: start rebound timeout
Jul 14 19:19:47 platform connmand[701]: DHCP: switch listening mode (2 ==> 1)
Jul 14 19:19:47 platform connmand[701]: DHCP: sending DHCP rebound request
Jul 14 19:19:47 platform connmand[701]: DHCP: received DHCP packet with message
type 6 (current state 4)
Jul 14 19:19:47 platform connmand[701]: DHCP: processed DHCP packet (new state
4)
Jul 14 19:19:50 platform connmand[701]: DHCP: restart DHCP timeout
Jul 14 19:19:50 platform connmand[701]: DHCP: restart DHCP (retries 1)
Jul 14 19:19:50 platform connmand[701]: DHCP: sending DHCP discover request
Jul 14 19:19:50 platform connmand[701]: DHCP: received DHCP packet with message
type 2 (current state 0)
Jul 14 19:19:50 platform connmand[701]: DHCP: start request (retries 0)
Jul 14 19:19:50 platform connmand[701]: DHCP: sending DHCP select request
Jul 14 19:19:50 platform connmand[701]: DHCP: received DHCP packet with message
type 5 (current state 1)
Jul 14 19:19:50 platform connmand[701]: DHCP: switch listening mode (1 ==> 0)
Jul 14 19:19:50 platform connmand[701]: DHCP: start bound
Jul 14 19:19:50 platform connmand[701]: DHCP: processed DHCP packet (new state
2)
Jul 15 07:19:51 platform connmand[701]: DHCP: start renew timeout
Jul 15 07:19:51 platform connmand[701]: DHCP: switch listening mode (0 ==> 2)
Jul 15 07:19:51 platform connmand[701]: DHCP: sending DHCP renew request
Jul 15 13:19:51 platform connmand[701]: DHCP: start renew timeout
Jul 15 13:19:51 platform connmand[701]: DHCP: sending DHCP renew request
I think this means that the DHCP restart logic has long been broken and this
change fixes it.
> But I suspect the proper place to fix it is in g_dhcp_client_start, here:
>
>
> if (dhcp_client->retry_times == 0) {
> g_free(dhcp_client->assigned_ip);
> dhcp_client->assigned_ip = NULL;
>
> dhcp_client->state = INIT_SELECTING;
> re = switch_listening_mode(dhcp_client, L2);
> if (re != 0)
> return re;
>
> dhcp_client->xid = rand();
> dhcp_client->start = time(NULL);
> }
>
> /* ... */
>
> send_discover(dhcp_client, addr);
>
>
> If my reading of the code is correct, it doesn't make sense to send DHCP
> DISCOVER requests unless state == INIT_SELECTING because otherwise we just
> ignore the response. Thoughts?
So I guess the only remaining question is where it should be fixed. Like I said
above, I think we should unconditionally set state to INIT_SELECTING if we're
going to be sending DHCP DISCOVER requests. If this makes sense to everyone
I'll go ahead and submit a patch.
Thoughts?
Thanks,
Forest
--
Forest Bond
http://www.alittletooquiet.net
http://www.rapidrollout.com
signature.asc
Description: Digital signature
_______________________________________________ connman mailing list [email protected] http://lists.connman.net/listinfo/connman
