ArcGIS Enterprise HA: portal second web adaptor not registered

Biboba commented 3 years ago

Community Note

Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request
Please do not leave "+1" or "me too" comments, they generate extra noise for issue followers and do not help prioritize the request

Module Version

3.1.1

Affected Resource(s)

ArcGIS_WebAdaptor
ArcGIS_Portal

Configuration Files

ArcGIS_Enterprise_HA.txt

Expected Behavior

The 2 webadaptors should be registered with Portal for ArcGIS and the 3 following URL should work: VM1: https://mapsportalqa01.company.com/geoportal VM2: https://mapsportalqa02.company.com/geoportal WebContextURL: https://mapsqa.company.com/geoportal

Actual Behavior

The second webadaptor is not registered with Portal for ArcGIS: VM1: https://mapsportalqa01.company.com/geoportal => is working VM2: https://mapsportalqa02.company.com/geoportal => is not working: returns error 500 "No portal is configured". WebContextURL: https://mapsqa.company.com/geoportal => is working thanks to healthcheck

In DSC log, everything seems to be successful on the webadaptor side:

22-Mar-21 1:28:53 AM: [MAPSPORTALQA01]: LCM:  [ Start  Set      ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]
22-Mar-21 1:28:53 AM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01] https://mapsportalqa01.company.com/arcgis/webadaptor
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01] Output of execution:- Configuring Web adaptor.

Successfully Registered.
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]  in 7.2080 seconds.
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]: LCM:  [ End    Resource ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]: LCM:  [ Start  Resource ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]: LCM:  [ Start  Test     ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]: LCM:  [ End    Test     ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]  in 0.0120 seconds.
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]: LCM:  [ Start  Set      ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Mar-21 1:29:03 AM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01] https://mapsportalqa01.company.com/geoportal/webadaptor
22-Mar-21 1:30:58 AM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01] Output of execution:- Configuring Web adaptor...

Successfully Registered.
22-Mar-21 1:30:58 AM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]  in 114.6010 seconds.
22-Mar-21 1:30:58 AM: [MAPSPORTALQA01]: LCM:  [ End    Resource ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Mar-21 1:30:58 AM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]
22-Mar-21 1:30:58 AM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]    in  126.8170 seconds.
22-Mar-21 1:30:58 AM: Operation 'Invoke CimMethod' complete.

Output is the same on MAPSPORTALQA01 for which webadaptor works.

Steps to Reproduce

Run the attached config. Once over, check the 2 portal webadaptor URL. The second one is not working.

Important Factoids

An HA proxy is configured to balance portal WebContextURL to each webadaptor: HAProxy: https://mapsqa.company.com/geoportal balancing with X-forwarded-host to: VM1: https://mapsportalqa01.company.com/geoportal VM2: https://mapsportalqa02.company.com/geoportal

Rerunning, the DSC config solves the issue though it is the same output from log

Any idea what could be the issue ?

Thanks !

cameronkroeker commented 3 years ago

Hi @Biboba,

In the directory where the Invoke-ArcGISConfiguration command was executed there should be a logs folder, can we check the ...\logs\mapsportalqa02\ArcGISWebAdaptor-<date>-<time>-Verbose.txt log file for mapsportalqa02? This should show us why it wasn't initially registered on the first run.

The portal web adaptor registration triggers a full mode reindex of portal content, which can take a long time. Perhaps it timed out, and the error was ignored.

Thanks, Cameron K.

Biboba commented 3 years ago

Hi @cameronkroeker, Thanks for your reply. The log file from "mapsportalqa02" was exactly the same as "mapsportalqa01": all the registrations successfull but still one was not registered. I had this issue 3 times in a row so I opened this issue but since then I have been applying the very same config multiple times without any issue...

cameronkroeker commented 3 years ago

Hi @Biboba,

This is a strange one, I don't really have a logical explanation as of what could have happened. Perhaps its a race condition of some sort, or portal/server sent a false positive that registration was successful but really wasn't. Not entirely sure though just grasping for straws. If it happens again, please send the full DSC logs of both nodes if possible. May even need to check portal/server debug level logs and compare time stamps of the web adaptor registration process with the dsc logs.

Thanks, Cameron K.

Biboba commented 3 years ago

Hello @cameronkroeker,

Just happened again !

MAPSPORTALQA01 log:

22-Apr-21 4:43:17 PM: [MAPSPORTALQA01]: LCM:  [ Start  Resource ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]
22-Apr-21 4:43:17 PM: [MAPSPORTALQA01]: LCM:  [ Start  Test     ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]
22-Apr-21 4:43:17 PM: [MAPSPORTALQA01]: LCM:  [ End    Test     ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]  in 0.0870 seconds.
22-Apr-21 4:43:17 PM: [MAPSPORTALQA01]: LCM:  [ Start  Set      ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]
22-Apr-21 4:43:17 PM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01] https://mapsportalqa01.company.com/arcgis/webadaptor
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01] Output of execution:- Configuring Web adaptor.

Successfully Registered.
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]  in 7.4600 seconds.
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]: LCM:  [ End    Resource ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa01]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]: LCM:  [ Start  Resource ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]: LCM:  [ Start  Test     ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]: LCM:  [ End    Test     ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]  in 0.0150 seconds.
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]: LCM:  [ Start  Set      ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01] https://mapsportalqa01.company.com/geoportal/webadaptor
22-Apr-21 4:43:48 PM: [MAPSPORTALQA01]:                            [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01] Output of execution:- Configuring Web adaptor...

Successfully Registered.
22-Apr-21 4:43:48 PM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]  in 19.8610 seconds.
22-Apr-21 4:43:48 PM: [MAPSPORTALQA01]: LCM:  [ End    Resource ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa01]
22-Apr-21 4:43:48 PM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]
22-Apr-21 4:43:48 PM: [MAPSPORTALQA01]: LCM:  [ End    Set      ]    in  31.5780 seconds.
22-Apr-21 4:43:48 PM: Operation 'Invoke CimMethod' complete.

MAPSPORTALQA02 log:

22-Apr-21 4:43:18 PM: [MAPSPORTALQA02]: LCM:  [ Start  Resource ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02]
22-Apr-21 4:43:18 PM: [MAPSPORTALQA02]: LCM:  [ Start  Test     ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02]
22-Apr-21 4:43:18 PM: [MAPSPORTALQA02]: LCM:  [ End    Test     ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02]  in 0.1310 seconds.
22-Apr-21 4:43:18 PM: [MAPSPORTALQA02]: LCM:  [ Start  Set      ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02]
22-Apr-21 4:43:18 PM: [MAPSPORTALQA02]:                            [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02] https://mapsportalqa02.company.com/arcgis/webadaptor
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]:                            [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02] Output of execution:- Configuring Web adaptor.

Successfully Registered.
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]: LCM:  [ End    Set      ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02]  in 6.6060 seconds.
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]: LCM:  [ End    Resource ]  [[ArcGIS_WebAdaptor]ConfigureServerWebAdaptormapsportalqa02]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]: LCM:  [ Start  Resource ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]: LCM:  [ Start  Test     ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]: LCM:  [ End    Test     ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02]  in 0.0120 seconds.
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]: LCM:  [ Start  Set      ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02]
22-Apr-21 4:43:28 PM: [MAPSPORTALQA02]:                            [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02] https://mapsportalqa02.company.com/geoportal/webadaptor
22-Apr-21 4:43:58 PM: [MAPSPORTALQA02]:                            [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02] Output of execution:- Configuring Web adaptor...

Successfully Registered.
22-Apr-21 4:43:58 PM: [MAPSPORTALQA02]: LCM:  [ End    Set      ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02]  in 34.4550 seconds.
22-Apr-21 4:43:58 PM: [MAPSPORTALQA02]: LCM:  [ End    Resource ]  [[ArcGIS_WebAdaptor]ConfigurePortalWebAdaptormapsportalqa02]
22-Apr-21 4:43:58 PM: [MAPSPORTALQA02]: LCM:  [ End    Set      ]
22-Apr-21 4:43:58 PM: [MAPSPORTALQA02]: LCM:  [ End    Set      ]    in  45.0910 seconds.
22-Apr-21 4:43:58 PM: Operation 'Invoke CimMethod' complete.

It guess it will be difficult to debug...

cameronkroeker commented 3 years ago

Hi @Biboba, is there any information in the portal logs indicating that the web adaptor registration initially failed? I recommend matching the time stamps of the dsc logs with the portal logs to see if there are any discrepancies.

Biboba commented 3 years ago

Yes indeed !

SEVERE  
Failed to register ArcGIS Web Adaptor 'mapsportalqa01.company.com' with the portal. java.lang.Exception: Rollback: SQLException in remove, Cannot commit when autoCommit is enabled.
2021-04-22T16:43:43,882 Portal Admin    MAPSPORTALQA02.COMPANY.COM      207001  5972

cameronkroeker commented 3 years ago

Yes indeed !

SEVERE    
Failed to register ArcGIS Web Adaptor 'mapsportalqa01.company.com' with the portal. java.lang.Exception: Rollback: SQLException in remove, Cannot commit when autoCommit is enabled.
2021-04-22T16:43:43,882   Portal Admin    MAPSPORTALQA02.COMPANY.COM      207001  5972

Great find! I think what may have happened here is portal failed to update the db, but must not have sent the error to Web Adaptor, so Web Adaptor thinks registration was successful. Then DSC continues based off the response received from this command:

C:\Program Files (x86)\Common Files\ArcGIS\WebAdaptor\IIS\10.8.1\Tools> .\ConfigureWebAdaptor.exe -m portal /w https://mapsportalqa02.company.com/geoportal/webadaptor /g https://mapsportalqa02.company.com:7443 /u siteadmin /p password /r false

I am not quite sure though what could be causing the error above, or why portal wouldn't be sending an error to the web adaptor tool. Are you able to consistently reproduce this? I wonder if it happens with 2 Web Adaptors and a single portal?

Biboba commented 3 years ago

Hello @cameronkroeker,

As mentionned before, it does not occur systematically but quite often with this configuration. Also it's an HA architecture (cf. config in my original post which is still the same) so there are 2 portals.

Thanks

cameronkroeker commented 3 years ago

Hello @cameronkroeker,

As mentionned before, it does not occur systematically but quite often with this configuration. Also it's an HA architecture (cf. config in my original post which is still the same) so there are 2 portals.

Thanks

Hi @Biboba, DSC succeeds and moves on because it received a success response from the web adaptor configure tool. I recommend reaching out to Esri technical support for them to help investigate the cause of portal not sending the proper error response to the web adaptor configure tool.

Thanks, Cameron K.

Biboba commented 2 years ago

Hi @cameronkroeker,

OK, thanks for your reply. I did not contact support as I was not able to reproduce systematically. Might have been a race condition ?

Let's see if it occurs on future deployment.

Esri / arcgis-powershell-dsc