search

F5Networks / f5-azure-arm-templates-v2

Azure Resource Manager Templates for quickly deploying BIG-IP services in Azure
22 stars 45 forks source link

length if undefined error in bigiptemplate failing onboarder extension #15

Closed JeffGiroux closed 2 years ago

JeffGiroux commented 2 years ago

Describe the bug

The quickstart template fails on the child bigipTemplate at the onboarder extension.

Expected behavior

Successful deployment and onboarding of BIG-IP instance

Current behavior

The child bigipTemplate fails during onboarder extension and therefore the BIG-IP fails to deploy.

error - will be pasted in comments

Possible solution

timeout or CSP API issues, retries, timeouts

Steps to reproduce

  1. deploy quickstart as-is by launching blue button
  2. fill in parameters, launch

Screenshots

n/a

Context

n/a

Your Environment

n/a

JeffGiroux commented 2 years ago

error:

{"code":"DeploymentFailed","message":"At least one resource deployment operation failed. Please list deployment operations for details. Please see https://aka.ms/DeployOperations for usage details.","details":[{"code":"VMExtensionProvisioningError","message":"VM has reported a failure when processing extension 'onboarder'. Error message: \"Enable failed: failed to execute command: command terminated with exit status=1\n[stdout]\ninstallation is completed.\n2022-07-12T16:14:31.157Z [20629]: info: Configuration file: /config/cloud/runtime-init.conf\n2022-07-12T16:14:31.177Z [20629]: info: Processing controls parameters\n2022-07-12T16:14:31.182Z [20629]: info: Validating provided declaration\n2022-07-12T16:14:31.252Z [20629]: info: Successfully validated declaration\n2022-07-12T16:14:31.254Z [20629]: info: Executing custom pre_onboard_enabled commands\n2022-07-12T16:14:31.267Z [20629]: info: Executing inline shell command: /usr/bin/setdb provision.extramb 1000\n2022-07-12T16:14:31.604Z [20629]: info: Shell command: /usr/bin/setdb provision.extramb 1000 execution completed; response: \n2022-07-12T16:14:31.605Z [20629]: info: Executing inline shell command: /usr/bin/setdb restjavad.useextramb true\n2022-07-12T16:14:31.987Z [20629]: info: Shell command: /usr/bin/setdb restjavad.useextramb true execution completed; response: \n2022-07-12T16:14:42.051Z [20629]: info: Resolving parameters\n2022-07-12T16:14:42.288Z [20629]: info: Interface:mgmt\n2022-07-12T16:14:42.289Z [20629]: info: MAC address found for mgmt: 00:0d:3a:ff:69:8b\n2022-07-12T16:14:42.290Z [20629]: error: Cannot read property 'length' of undefined\n2022-07-12T16:14:42.290Z [20629]: info: Sending F5 Teem report for failure case.\n2022-07-12T16:14:42.299Z [20629]: info: Interface:1.1\n2022-07-12T16:14:42.300Z [20629]: info: MAC adddress is not populated on 1.1 BIGIP interface. Trying to re-fetch interface data. Left attempts: 99\n2022-07-12T16:14:42.313Z [20629]: info: Interface:1.2\n2022-07-12T16:14:42.314Z [20629]: info: MAC adddress is not populated on 1.2 BIGIP interface. Trying to re-fetch interface data. Left attempts: 99\n2022-07-12T16:14:42.323Z [20629]: info: Interface:1.1\n2022-07-12T16:14:42.325Z [20629]: info: MAC adddress is not populated on 1.1 BIGIP interface. Trying to re-fetch interface data. Left attempts: 99\n2022-07-12T16:14:43.242Z [20629]: info: {\"id\":\"7362d1fa-79fb-c34d-1b1fbb44c998\",\"product\":\"BIG-IP\",\"cpuCount\":8,\"diskSize\":86016,\"memoryInMb\":32176,\"version\":\"16.1.2.2\",\"nicCount\":3,\"regKey\":\"LTTPZ-DDVLR-JFRGL-BWJPB-YTYKPJL\",\"platformId\":\"Z100\",\"hostname\":\"bigip1\",\"management\":\"10.0.0.11/24\",\"provisionedModules\":{\"ltm\":\"nominal\"},\"installedPackages\":{},\"environment\":{\"pythonVersion\":\"Python 2.7.5\",\"pythonVersionDetailed\":\"2.7.5 (default, Apr 7 2022, 12:13:41) \n[GCC 4.8.5 20150623 (Red Hat 4.8.5-16)]\",\"nodeVersion\":\"v6.9.1\",\"libraries\":{\"ssh\":\"OpenSSH_7.4p1, OpenSSL 1.0.2u-fips 20 Dec 2019\"}}}\n2022-07-12T16:14:53.756Z [20629]: info: Interface:1.1\n2022-07-12T16:14:53.757Z [20629]: info: MAC adddress is not populated on 1.1 BIGIP interface. Trying to re-fetch interface data. Left attempts: 98\n2022-07-12T16:14:53.770Z [20629]: info: Interface:1.2\n2022-07-12T16:14:53.771Z [20629]: info: MAC adddress is not populated on 1.2 BIGIP interface. Trying to re-fetch interface data. Left attempts: 98\n2022-07-12T16:14:53.783Z [20629]: info: Interface:1.1\n2022-07-12T16:14:53.785Z [20629]: info: MAC adddress is not populated on 1.1 BIGIP interface. Trying to re-fetch interface data. Left attempts: 98\n2022-07-12T16:14:55.062Z [20629]: info: F5 Teem report was successfully sent for failure case.\n2022-07-12T16:14:55.066Z [20629]: info: Cannot read property 'length' of undefined\n2022-07-12T16:15:03.779Z [20629]: info: Interface:1.1\n2022-07-12T16:15:03.780Z [20629]: info: MAC address found for 1.1: 00:0d:3a:ff:66:88\n2022-07-12T16:15:03.780Z [20629]: info: Local interface 1 MAC address 000d3aff6688 matches Azure network interface 1 MAC address 000d3aff6688\n2022-07-12T16:15:03.790Z [20629]: info: Interface:1.2\n2022-07-12T16:15:03.790Z [20629]: info: MAC address found for 1.2: 00:0d:3a:ff:6b:da\n2022-07-12T16:15:03.791Z [20629]: info: Local interface 2 MAC address 000d3aff6bda matches Azure network interface 2 MAC address 000d3aff6bda\n2022-07-12T16:15:03.803Z [20629]: info: Interface:1.1\n2022-07-12T16:15:03.805Z [20629]: info: MAC address found for 1.1: 00:0d:3a:ff:66:88\n2022-07-12T16:15:03.810Z [20629]: info: Local interface 1 MAC address 000d3aff6688 matches Azure network interface 1 MAC address 000d3aff6688\n\n[stderr]\n\"\r\n\r\nMore information on troubleshooting is available at https://aka.ms/VMExtensionCSELinuxTroubleshoot "}]}

mikeshimkus commented 2 years ago

This was fixed in issue ESECLDTPLT-3116. Will be in the next runtime init release. Until then, you should be able to test with this pre-release version for the bigIpRuntimeInitPackageUrl parameter: https://cdn.f5.com/product/cloudsolutions/f5-bigip-runtime-init/develop/develop/dist/f5-bigip-runtime-init-1.5.0-1.gz.run

JeffGiroux commented 2 years ago

still failing, can't login to ssh to see any other logs. Here's the azure template deployment error on the bigiptemplate now...

OS Provisioning for VM 'giroux2-bigip-vm' did not finish in the allotted time. The VM may still finish provisioning successfully. Please check provisioning state later.

region = westus2

JeffGiroux commented 2 years ago

After a few more attempts, I tried two different deployments in "West US2" and two more in "West US". I had a successful of each, and I also had a failure in each. I was able to successfully login via SSH, and also validated the demo app worked when deploying full/new stack.

de1chk1nd commented 2 years ago

Hi, agree with jeff. just ran into the issue, too. Last week friday it was working, now it is failing with above error. Deployment in Azure/Germany.

Also tried the new runtime-init link - no success.

"message": "VM has reported a failure when processing extension 'onboarder'. Error message: \"Enable failed: failed to execute command: command terminated with exit status=1\n[stdout]\n22-07-18T09:44:17.708Z [27519]: info: Processing controls parameters\n2022-07-18T09:44:17.712Z [27519]: info: Validating provided declaration\n2022-07-18T09:44:17.766Z [27519]: info: Successfully validated declaration\n2022-07-18T09:44:17.769Z [27519]: info: Executing custom pre_onboard_enabled commands\n2022-07-18T09:44:17.771Z [27519]: info: Executing inline shell command: /usr/bin/setdb provision.extramb 1000\n2022-07-18T09:44:17.891Z [27519]: info: Shell command: /usr/bin/setdb provision.extramb 1000 execution completed; response: \n2022-07-18T09:44:17.896Z [27519]: info: Executing inline shell command: /usr/bin/setdb restjavad.useextramb true\n2022-07-18T09:44:18.008Z [27519]: info: Shell command: /usr/bin/setdb restjavad.useextramb true execution completed; response: \n2022-07-18T09:44:18.040Z [27519]: info: Resolving parameters\n2022-07-18T09:44:18.238Z [27519]: info: Interface:1.2\n2022-07-18T09:44:18.241Z [27519]: info: MAC address found for 1.2: 00:22:48:5b:e2:4d\n2022-07-18T09:44:18.243Z [27519]: info: Local interface 2 MAC address 0022485be24d matches Azure network interface 2 MAC address 0022485be24d\n2022-07-18T09:44:18.249Z [27519]: info: Interface:mgmt\n2022-07-18T09:44:18.251Z [27519]: info: MAC address found for mgmt: 00:22:48:5b:e5:f9\n2022-07-18T09:44:18.254Z [27519]: info: Local interface 0 MAC address 0022485be5f9 matches Azure network interface 0 MAC address 0022485be5f9\n2022-07-18T09:44:18.261Z [27519]: info: Interface:1.1\n2022-07-18T09:44:18.263Z [27519]: info: MAC address found for 1.1: 00:22:48:5b:e6:e9\n2022-07-18T09:44:18.266Z [27519]: info: Local interface 1 MAC address 0022485be6e9 matches Azure network interface 1 MAC address 0022485be6e9\n2022-07-18T09:44:18.272Z [27519]: info: Interface:1.1\n2022-07-18T09:44:18.274Z [27519]: info: MAC address found for 1.1: 00:22:48:5b:e6:e9\n2022-07-18T09:44:18.276Z [27519]: info: Local interface 1 MAC address 0022485be6e9 matches Azure network interface 1 MAC address 0022485be6e9\n2022-07-18T09:44:18.394Z [27519]: error: <!DOCTYPE html PUBLIC \"-//W3C//DTD XHTML 1.0 Strict//EN\" \"http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd\">\r\n<html xmlns=\"http://www.w3.org/1999/xhtml\">\r\n\r\n<meta http-equiv=\"Content-Type\" content=\"text/html; charset=iso-8859-1\"/>\r\n404 - File or directory not found.\r\n<style type=\"text/css\">\r\n\r\n\r\n\r\n\r\n<div id=\"header\">

Server Error

\r\n<div id=\"content\">\r\n <div class=\"content-container\">
\r\n

404 - File or directory not found.

\r\n

The resource you are looking for might have been removed, had its name changed, or is temporarily unavailable.

\r\n
\r\n\r\n\r\n\r\n\n2022-07-18T09:44:18.431Z [27519]: info: Sending F5 Teem report for failure case.\n2022-07-18T09:44:18.700Z [27519]: warn: Problem with getting data from /mgmt/tm/sys/license endpoint. Leaving regKey with default value\n2022-07-18T09:44:18.705Z [27519]: info: {\"id\":\"2021b35c-1616-6645-2ee9ea115460\",\"product\":\"BIG-IP\",\"cpuCount\":8,\"diskSize\":56320,\"memoryInMb\":32176,\"version\":\"16.1.2.1\",\"nicCount\":3,\"platformId\":\"Z100\",\"hostname\":\"bigip1\",\"management\":\"10.1.1.5/24\",\"provisionedModules\":{\"ltm\":\"nominal\"},\"installedPackages\":{},\"environment\":{\"pythonVersion\":\"Python 2.7.5\",\"pythonVersionDetailed\":\"2.7.5 (default, Dec 22 2021, 16:19:59) \n[GCC 4.8.5 20150623 (Red Hat 4.8.5-16)]\",\"nodeVersion\":\"v6.9.1\",\"libraries\":{\"ssh\":\"OpenSSH_7.4p1, OpenSSL 1.0.2u-fips 20 Dec 2019\"}}}\n2022-07-18T09:44:18.994Z [27519]: error: Device is not licensed yet\n\n[stderr]\n\"\r\n\r\nMore information on troubleshooting is available at https://aka.ms/VMExtensionCSELinuxTroubleshoot "

mikeshimkus commented 2 years ago

@de1chk1nd This looks like a different error from the "length of undefined" Jeff was seeing, please open a new Github issue. If you can provide /config/cloud/runtime-init.conf and the template input parameters too it will be helpful.

mikeshimkus commented 2 years ago

@JeffGiroux We released a new version of runtime init on Friday that fixes this: https://github.com/F5Networks/f5-bigip-runtime-init/releases/tag/1.5.1 (successfully ran 12 concurrent quickstart/failover tests to verify).

While the previous dev build increased the time between retries, the issue was mostly happening on the first set of requests to grab the NIC info so that didn't fully fix it. Optimized to make a single metadata request and reuse the response for all info we need.

The link to the package on CDN is here: https://cdn.f5.com/product/cloudsolutions/f5-bigip-runtime-init/v1.5.1/dist/f5-bigip-runtime-init-1.5.1-1.gz.run

de1chk1nd commented 2 years ago

@mikeshimkus done: https://github.com/F5Networks/f5-azure-arm-templates-v2/issues/17

shyawnkarim commented 2 years ago

Closing.

This issue was resolved with Runtime-init Release 15.1.