From patchwork Wed Jun 22 09:32:30 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Ryan Harkin X-Patchwork-Id: 70617 Delivered-To: patch@linaro.org Received: by 10.140.28.4 with SMTP id 4csp2452544qgy; Wed, 22 Jun 2016 02:32:36 -0700 (PDT) X-Received: by 10.66.194.68 with SMTP id hu4mr33677494pac.23.1466587956477; Wed, 22 Jun 2016 02:32:36 -0700 (PDT) Return-Path: Received: from ml01.01.org (ml01.01.org. [2001:19d0:306:5::1]) by mx.google.com with ESMTPS id un5si21721564pab.174.2016.06.22.02.32.36 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Wed, 22 Jun 2016 02:32:36 -0700 (PDT) Received-SPF: pass (google.com: best guess record for domain of edk2-devel-bounces@lists.01.org designates 2001:19d0:306:5::1 as permitted sender) client-ip=2001:19d0:306:5::1; Authentication-Results: mx.google.com; dkim=neutral (body hash did not verify) header.i=@linaro.org; spf=pass (google.com: best guess record for domain of edk2-devel-bounces@lists.01.org designates 2001:19d0:306:5::1 as permitted sender) smtp.mailfrom=edk2-devel-bounces@lists.01.org; dmarc=fail (p=NONE dis=NONE) header.from=linaro.org Received: from [127.0.0.1] (localhost [IPv6:::1]) by ml01.01.org (Postfix) with ESMTP id 261541A1E08; Wed, 22 Jun 2016 02:33:06 -0700 (PDT) X-Original-To: edk2-devel@lists.01.org Delivered-To: edk2-devel@lists.01.org Received: from mail-lf0-x22b.google.com (mail-lf0-x22b.google.com [IPv6:2a00:1450:4010:c07::22b]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by ml01.01.org (Postfix) with ESMTPS id BD9391A1E04 for ; Wed, 22 Jun 2016 02:33:04 -0700 (PDT) Received: by mail-lf0-x22b.google.com with SMTP id f6so68125318lfg.0 for ; Wed, 22 Jun 2016 02:32:34 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; h=mime-version:in-reply-to:references:from:date:message-id:subject:to :cc:content-transfer-encoding; bh=7cETuYvMKHP3JRA29xt1QzIARciq4wQfh/N/nlAB2co=; b=e0CQ7BeSfq23+pET07wcngaA0db5hVeOEGVRm21AfgEj1oAUDYANiO8zZWFpptGsos yfhz38GvBkLSrQRQPGBjZiLELcklC+mPDwPivEjwGk1og49LWFfaJ2GCtOblH9yqC2nD MNzQJQxs2L6HBmYAI2jo8cfH15hlm/JJ6i+Hk= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to:cc:content-transfer-encoding; bh=7cETuYvMKHP3JRA29xt1QzIARciq4wQfh/N/nlAB2co=; b=V9cngL8OvxReRe/HBg+Ia7ANGOBYqGuMTwLp86bDGejzb9j7mL9hSLGse+FjW+dY3f qC+2IIdxY5ZW9Rog9+x5+8OHpOboAiAez/nZlpvWMvFu2/uwHhcUfl01t9WfNUtrU/SV Ma51bKzR6iSYTPd3r+gmBCFy3+NoIc7CDY6hhMvS9loGfgjohFpSGmS9hJBFvV24y0Gh z770SBkOyt/SeyluxeYJ4JuFXqAnENmqnOUzpeAqDrBpC+7EA5cWY5hoKDqCQAN5j2nH 8DoiSyb+43EWqj2R+uDiTzs+GMuz0uL2G931uS8h58dTCDdGjX9oOoadUW/FaJrm+a87 HCgQ== X-Gm-Message-State: ALyK8tLZFfTfaXNplG9srWfDayauEsev3WE9hySeEPd8xSmG6AfE1iYINjXLgXTjCxI6dlZpdGudGXZASZaup2gy X-Received: by 10.25.149.6 with SMTP id x6mr6790659lfd.106.1466587951115; Wed, 22 Jun 2016 02:32:31 -0700 (PDT) MIME-Version: 1.0 Received: by 10.25.35.145 with HTTP; Wed, 22 Jun 2016 02:32:30 -0700 (PDT) In-Reply-To: <895558F6EA4E3B41AC93A00D163B7274137B60CB@SHSMSX103.ccr.corp.intel.com> References: <1456374135-14732-1-git-send-email-jiaxin.wu@intel.com> <1456374135-14732-2-git-send-email-jiaxin.wu@intel.com> <895558F6EA4E3B41AC93A00D163B7274137B5947@SHSMSX103.ccr.corp.intel.com> <895558F6EA4E3B41AC93A00D163B7274137B5B5E@SHSMSX103.ccr.corp.intel.com> <895558F6EA4E3B41AC93A00D163B7274137B5C69@SHSMSX103.ccr.corp.intel.com> <895558F6EA4E3B41AC93A00D163B7274137B60CB@SHSMSX103.ccr.corp.intel.com> From: Ryan Harkin Date: Wed, 22 Jun 2016 10:32:30 +0100 Message-ID: To: "Wu, Jiaxin" Subject: Re: [edk2] [Patch 1/4] MdeModulePkg: Change the default IPv4 config policy X-BeenThere: edk2-devel@lists.01.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: EDK II Development List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Cc: "Ye, Ting" , "Fu, Siyuan" , edk2-devel-01 Errors-To: edk2-devel-bounces@lists.01.org Sender: "edk2-devel" On 22 June 2016 at 09:45, Wu, Jiaxin wrote: > Hi Ryan, > I have root cause the issue: > Wow! You found it! I'm very pleased about that :-) > Let me analyze this problem for you according below steps: > 1 .First PXE boot, then boot to shell; > 2. ifconfig -s eth0 dhcp (Success); > 3. Reboot and do PXE, then boot to shell;----> The issue is enrolled by here!!!! > > On this reboot, policy is DHCP (Changed by step2). So, Ip4Dxe driver will try to get one IP address from DHCP server automatically. Before it get the IP address successfully, the IpSb->State will be always in IP4_SERVICE_STARTED status until the Instance->Dhcp4Event is triggered, then it can be changed to IP4_SERVICE_CONFIGED. But the DHCP process will be interrupted by PXE boot, which will change the policy to static, and the Instance->Dhcp4Event will be also closed directly. However, current implementation doesn't update the IpSb->State to IP4_SERVICE_UNSTARTED status in such case. So, failure happened! > That makes perfect sense. > Why not happened in simulator platform? Because Ip4Dxe driver finished the DHCP process (DORA) and the IpSb->State has been changed to IP4_SERVICE_CONFIGED before PXE set the policy to DHCP. > Ah, a timing problem! > 4. ifconfig -s eth0 dhcp (Platform failed to get IP address no matter how many times retried.) > > > The corresponding patch will be send out later to fix this issue, so, please help to verify it. > Thanks a lot for looking at this. I'm happy to test a fix. Perhaps you could also consider adding this diff into your fix? It's slightly more efficient in the case with no error, but I think it's a little bit easier to follow the flow and intention of the code with my diff. But it's ok if you don't like it, it's your code. Regards, Ryan. > > Thanks and Best Regard! > Jiaxin > > >> -----Original Message----- >> From: Wu, Jiaxin >> Sent: Wednesday, June 22, 2016 11:35 AM >> To: 'Ryan Harkin' >> Cc: Ye, Ting ; Fu, Siyuan ; 'edk2- >> devel-01' >> Subject: RE: [edk2] [Patch 1/4] MdeModulePkg: Change the default IPv4 >> config policy >> >> Hi Ryan, >> I can reproduce the issue on my real platform now, thank you for your >> reporting. I will find the root cause and fix it. If have any process, I will inform >> you. >> >> Thanks again. >> Jiaxin >> >> > -----Original Message----- >> > From: Wu, Jiaxin >> > Sent: Wednesday, June 22, 2016 10:41 AM >> > To: Ryan Harkin >> > Cc: Ye, Ting ; Fu, Siyuan ; >> > edk2- >> > devel-01 >> > Subject: RE: [edk2] [Patch 1/4] MdeModulePkg: Change the default IPv4 >> > config policy >> > >> > Ryan, >> > >> > > There could be a bug here, I suppose. Why is >> > > NetLibCreateServiceChild returning EFI_UNSUPPORTED? I guess I need >> > > to investigate this some >> > more. >> > > >> > > Continuing, at this point Status is still EFI_UNSUPPORTED, so this >> > > is caught line 958 and we return from the function. That looks like >> > > a bug. If not, it could do with a comment explaining why we've just >> > > handled the EFI_UNSUPPORTED error without returning, yet we return >> > here anyway. >> > >> > Ip4Dxe driver will try to get one IP address from DHCP server >> > automatically if policy is DHCP, so DHCPv4 Service Binding protocol is >> > required for this operation. If DHCPv4 Service Binding protocol is not >> > ready, the Ip4Dxe should register a notify to wait this Service >> > Binding protocol ready. We can't guarantee DHCPv4 Service has been >> > started before Ip4 Service. So, EFI_UNSUPPORTED status check for >> > NetLibCreateServiceChild is reasonable and correct here. >> > According your below test patch, you allow Ip4StartAutoConfig() >> > function continue the steps even DHCPv4 Service is not ready, this is >> > not allowed because no DHCP instance has been created, then ASSERT >> > happened. You don't need to do that. You can see the >> > Ip4Config2OnDhcp4SbInstalled() notify function, once the DHCPv4 >> > service binding protocol is installed in the system, Ip4StartAutoConfig() will >> be recalled again. >> > >> > > > I don't have wireshark set up, but I'll try to get it working and >> > > > send you a trace. >> > > > >> > > > However, I suspect that DHCP service (Is that the DORA you >> > > > mentioned?) is not being restarted for some reason, so in that >> > > > case, no packets would be sent out. >> > >> > For this confusion, the packet captured from wireshark can help us >> > know whether there is any packet out or not. >> > >> > Thanks. >> > Jiaxin >> > >> > >> > > -----Original Message----- >> > > From: edk2-devel [mailto:edk2-devel-bounces@lists.01.org] On Behalf >> > > Of Ryan Harkin >> > > Sent: Wednesday, June 22, 2016 2:12 AM >> > > To: Wu, Jiaxin >> > > Cc: Ye, Ting ; Fu, Siyuan ; >> > > edk2- >> > > devel-01 >> > > Subject: Re: [edk2] [Patch 1/4] MdeModulePkg: Change the default >> > > IPv4 config policy >> > > >> > > Hi Jiaxin, >> > > >> > > On 21 June 2016 at 12:20, Ryan Harkin wrote: >> > > > Hi Jiaxin, >> > > > >> > > > On 21 June 2016 at 12:10, Wu, Jiaxin wrote: >> > > >> Hi Ryan, >> > > >> >> > > >> I can't reproduce your issue on NT32, I will try it in a real platform later. >> > > >> >> > > > >> > > > I am unable to reproduce the problem on my "FVP models" (a type of >> > > > emulator) either. The models use a different ethernet device than >> > > > my hardware. >> > > > >> > > > >> > > >>> On first boot, policy is static, it gets changed to DHCP, "ifconfig -s >> > > >>> eth0 dhcp" works. On reboot, policy is dhcp, PXE changes it a couple >> > > >>> of times, then drops to the shell with is set to static again. >> > > >>> "ifconfig -s eth0 dhcp" fails no matter how many times I reboot. >> > > >> >> > > >> First PXE boot --> ifconfig -s eth0 dhcp (Success) --> reboot, >> > > >> then PXE --> ifconfig -s eth0 dhcp (Your platform failed here, >> > > >> but my parts is always in a success no matter how many times I >> > > >> tried.) >> > > >> >> > > >>> It's only when I "ifconfig -s eth0 static ...." then "ifconfig >> > > >>> -s >> > > >>> eth0 dhcp" that DHCP obtains an IP address again. >> > > >>> >> > > >>> It could easily be a bug in the LAN9118 driver too, but there's >> > > >>> a bug somewhere, because it isn't working as we expect :-O >> > > >> >> > > >> So, to help us analyze problem, could you sent me one wireshark >> > > >> packet >> > > for the above steps? >> > > >> >> > > > >> > > > I don't have wireshark set up, but I'll try to get it working and >> > > > send you a trace. >> > > > >> > > > However, I suspect that DHCP service (Is that the DORA you >> > > > mentioned?) is not being restarted for some reason, so in that >> > > > case, no packets would be sent out. >> > > > >> > > > I don't know how the DHCP service is handled or started, but I'll >> > > > try and find the points in the code where it's started and stopped >> > > > and add some trace to see if there are any errors. Any >> > > > suggestions of where to place some DEBUG would be welcome. >> > > > >> > > >> > > I decided to add DEBUG statements to function Ip4StartAutoConfig in >> > > Ip4Config2Impl.c. I appended my DEBUG to the end of each line, so I >> > > didn't change the line numbering when compared to the upstream >> > > version, currently last modified here: >> > > 364f4efa444150df3f074f563374dce1e153adc6 >> > > >> > > The debug code I added to each branch in the function looks like this: >> > > >> > > DEBUG ((EFI_D_ERROR, "%a:%d Instance->Policy=%d\n", >> __FUNCTION__, >> > > __LINE__, Instance->Policy)); >> > > >> > > Therefore, I can trace which branches the code is taking. >> > > >> > > On first boot, as expected, I can see that Ip4StartAutoConfig is not >> > > called at all. The default policy is static, so I'd expect that. >> > > >> > > Then, when I configure DHCP from Shell, I see the following debug: >> > > >> > > Ip4StartAutoConfig:921 Instance->Policy=0 >> > > Ip4StartAutoConfig:1032 Instance->Policy=0 >> > > >> > > This tells me that NetLibCreateServiceChild, gBS->OpenProtocol and >> > > Dhcp4->Configure succeeded and the DHCP process was started. >> > > >> > > That all looks good. So I reset the board and see this debug on boot: >> > > >> > > Warning: LAN9118 Driver in stopped state >> > > Ip4StartAutoConfig:921 Instance->Policy=1 >> > > Ip4StartAutoConfig:943 Instance->Policy=1 >> > > Ip4StartAutoConfig:947 Instance->Policy=1 >> > > Ip4StartAutoConfig:958 Instance->Policy=1 >> > > Ip4StartAutoConfig:921 Instance->Policy=1 >> > > Ip4StartAutoConfig:943 Instance->Policy=1 >> > > Ip4StartAutoConfig:958 Instance->Policy=1 >> > > Ip4StartAutoConfig:921 Instance->Policy=1 >> > > Ip4StartAutoConfig:962 Instance->Policy=1 >> > > Ip4StartAutoConfig:1032 Instance->Policy=1 >> > > EhcExecTransfer: transfer failed with 2 >> > > EhcControlTransfer: error - Device Error, transfer - 2 Press ENTER >> > > to boot now or any other key to show the Boot Menu in 8 seconds >> > > >> > > Booting EFI USB Device >> > > Booting EFI Misc Device >> > > Booting EFI Misc Device 1 >> > > Booting EFI Network >> > > ..PXE-E99: Unexpected network error. >> > > Booting EFI Internal Shell >> > > add-symbol-file >> > > >> > >> /working/platforms/uefi/edk2/Build/ArmJuno/DEBUG_GCC49/AARCH64/Sh >> > > ellPkg/Application/Shell/Shell/DEBUG/Shell.dll >> > > 0xF86C4000 >> > > Loading driver at 0x000F86C3000 EntryPoint=0x000F86C4000 Shell.efi >> > > >> > > Shell> ifconfig -s eth0 dhcp >> > > Ip4StartAutoConfig:921 Instance->Policy=0 >> > > Ip4StartAutoConfig:924 Instance->Policy=0 >> > > >> > > >> > > So I can see that on boot, because the saved policy is DHCP, the >> > > code taking a few error branches. >> > > >> > > First off "NetLibCreateServiceChild" returns EFI_UNSUPPORTED. The >> > > comments say this means "No DHCPv4 Service Binding protocol, >> > > register a notify.". Dhcp4SbNotifyEvent is NULL, so we create a notify >> event. >> > > >> > > There could be a bug here, I suppose. Why is >> > > NetLibCreateServiceChild returning EFI_UNSUPPORTED? I guess I need >> > > to investigate this some >> > more. >> > > >> > > Continuing, at this point Status is still EFI_UNSUPPORTED, so this >> > > is caught line 958 and we return from the function. That looks like >> > > a bug. If not, it could do with a comment explaining why we've just >> > > handled the EFI_UNSUPPORTED error without returning, yet we return >> > here anyway. >> > > >> > > I applied this diff to fix the suspected bug: >> > > >> > > diff --git a/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c >> > > b/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c >> > > index a1de443..fb8a46a 100644 >> > > --- a/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c >> > > +++ b/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c >> > > @@ -953,9 +953,7 @@ Ip4StartAutoConfig ( >> > > &Instance->Registration >> > > ); >> > > } >> > > - } >> > > - >> > > - if (EFI_ERROR (Status)) { >> > > + } else if (EFI_ERROR (Status)) { >> > > return Status; >> > > } >> > > >> > > >> > > Now, after first boot, I see this output when I run "ifconfig -s eth0 dhcp". >> > > Basically the same as before: >> > > >> > > Shell> ifconfig -s eth0 dhcp >> > > Shell> tAutoConfig:921 Instance->Policy=0 >> > > Ip4StartAutoConfig:1030 Instance->Policy=0 >> > > >> > > Then, I reset the board and then it ASSERTs: >> > > >> > > Warning: LAN9118 Driver in stopped state >> > > Ip4StartAutoConfig:921 Instance->Policy=1 >> > > Ip4StartAutoConfig:943 Instance->Policy=1 >> > > Ip4StartAutoConfig:947 Instance->Policy=1 >> > > Ip4StartAutoConfig:960 Instance->Policy=1 >> > > >> > > ASSERT_EFI_ERROR (Status = Invalid Parameter) ASSERT [Ip4Dxe] >> > > >> > >> /working/platforms/uefi/edk2/MdeModulePkg/Universal/Network/Ip4Dxe/ >> > > Ip4Config2Impl.c(972): >> > > !EFI_ERROR (Status) >> > > >> > > This is because gBS->OpenProtocol returns Invalid Parameter. >> > > >> > > So it looks like my diff wasn't a bug fix at all. Or, there is another bug? >> > > >> > > What do you think? >> > > >> > > Regards, >> > > Ryan. >> > > _______________________________________________ >> > > edk2-devel mailing list >> > > edk2-devel@lists.01.org >> > > https://lists.01.org/mailman/listinfo/edk2-devel _______________________________________________ edk2-devel mailing list edk2-devel@lists.01.org https://lists.01.org/mailman/listinfo/edk2-devel diff --git a/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c b/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c index d0fa132..7757718 100644 --- a/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c +++ b/MdeModulePkg/Universal/Network/Ip4Dxe/Ip4Config2Impl.c @@ -940,22 +940,21 @@ Ip4StartAutoConfig ( &Instance->Dhcp4Handle ); - if (Status == EFI_UNSUPPORTED) { - // - // No DHCPv4 Service Binding protocol, register a notify. - // - if (Instance->Dhcp4SbNotifyEvent == NULL) { - Instance->Dhcp4SbNotifyEvent = EfiCreateProtocolNotifyEvent ( - &gEfiDhcp4ServiceBindingProtocolGuid, - TPL_CALLBACK, - Ip4Config2OnDhcp4SbInstalled, - (VOID *) Instance, - &Instance->Registration - ); - } - } - if (EFI_ERROR (Status)) { + if (Status == EFI_UNSUPPORTED) {^M + //^M + // No DHCPv4 Service Binding protocol, register a notify.^M + //^M + if (Instance->Dhcp4SbNotifyEvent == NULL) {^M + Instance->Dhcp4SbNotifyEvent = EfiCreateProtocolNotifyEvent (^M + &gEfiDhcp4ServiceBindingProtocolGuid,^M + TPL_CALLBACK,^M + Ip4Config2OnDhcp4SbInstalled,^M + (VOID *) Instance,^M + &Instance->Registration^M + );^M + }^M + }^M return Status; }