REST call returns with HTTP 502 error

Last updated
Save as PDF
Share
1. Share
2. Tweet
3. Share

Views:: 458

Visibility:: Public

Votes:: 0

Category:: ontap-9

Specialty:: CORE

Last Updated:

Applies to

ONTAP 9
REST PATCH to /api/snapmirror

Issue

A REST API call PATCH is executed against a Snapmirror <relationship-id> to attempt to quiesce the relationship. After the specified return_timeout passed, ONTAP returns HTTP/502 error instead of expected HTTP/200 or HTTP/202:

> curl -ik -s -u <username>:<password> -X PATCH "https://<cluster_mgmt_lif>/api/snapmirror/relationships/<relationship-id>?failover=false&force-failover=false&force=false&failback=false&return_timeout=120" -H "accept: application/json" -H "Content-Type: application/json" -d "{ \"state\": \"paused\"}"

HTTP/1.1 502 Proxy Error

Date: Wed, 03 Aug 2022 10:13:41 GMT

Server: Apache

X-Content-Type-Options: nosniff

Cache-Control: no-cache,no-store,must-revalidate

Content-Length: 341

Content-Type: text/html; charset=iso-8859-1



<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">

<html><head>

<title>502 Proxy Error</title>

</head><body>

<h1>Proxy Error</h1>

<p>The proxy server received an invalid

response from an upstream server.<br />

The proxy server could not handle the request<p>Reason: <strong>Error reading from remote server</strong></p></p>

</body></html>

Note: In above example, the command was executed 10:11:41 with a return_timeout of 120sec (which is the maximum ONTAP REST supports)

apache_access.log shows HTTP/502 error, but in the context of surrounding log entries it is delayed by 5min + return_timeout:

[Wed Aug 03 10:18:38.554471 2022 +0000] "POST /servlets/netapp.servlets.admin.XMLrequest_filer HTTP/1.0" 200 190360 1537002 - 0 - 127.0.0.1 name-mapping-get-iter [Wed Aug 03 10:13:41.088515 2022 +0000] "PATCH /api/snapmirror/relationships/<relationship-id>?failover=false&force-failover=false&force=false&failback=false&return_timeout=120 HTTP/1.1" 502 341 300034196 - 0 + 127.0.0.1 - [Wed Aug 03 10:18:40.333797 2022 +0000] "POST /servlets/netapp.servlets.admin.XMLrequest_filer HTTP/1.0" 200 191798 1701289 - 0 - 127.0.0.1 name-mapping-get-iter

audit.log shows the request returning successful long after return_timeout and HTTP/502 error:

Wed Aug 03 2022 10:13:41 +00:00 [kern_audit:info:2561] 8503e80000a75342 :: <cluster_name>:http :: <REST-client-IP-address>:53495 :: <cluster_name>:<user_name> :: PATCH /api/snapmirror/relationships/<relationship-id>?failover=false&force-failover=false&force=false&failback=false&return_timeout=120 : { "state": "paused"} :: Pending Wed Aug 03 2022 10:13:41 +00:00 [kern_audit:info:3229] 8503e80000a75342 :: <cluster_name>:http :: <REST-client-IP-address>:53495 :: <cluster_name>:<user_name> :: PATCH /api/snapmirror/relationships/<relationship-id>?failover=false&force-failover=false&force=false&failback=false&return_timeout=120 HTTP/1.1 :: Error: 502 Proxy Error Wed Aug 03 2022 11:14:39 +00:00 [kern_audit:info:2561] 8503e80000a75342 :: <cluster_name>:http :: <REST-client-IP-address>:53495 :: <cluster_name>:<user_name> :: PATCH /api/snapmirror/relationships/<relationship-id>?failover=false&force-failover=false&force=false&failback=false&return_timeout=120 : { "state": "paused"} :: Success:

apache_error.log reports timeout from REST API service 127.0.0.1:936 5min after the original request timed out:

[Wed Aug 03 10:18:41.122493 2022 +0000] [proxy_http:error] [pid 12297:tid 34379805440] (70007)The timeout specified has expired: [client <REST-client-IP-address>:53495] AH01102: error reading status line from remote server 127.0.0.1:936

[Wed Aug 03 10:18:41.122529 2022 +0000] [proxy:error] [pid 12297:tid 34379805440] [client <REST-client-IP-address>:53495] AH00898: Error reading from remote server returned by /api/snapmirror/relationships/<relationship-id>

mgwd.log shows a ZSM error after return_timeout, and successful return of snapmirror_relationship_rest only way later:

Wed Aug 03 2022 10:13:41 +00:00 [kern_mgwd:info:2561] ZSM: parse error=Document is empty  {na_zapi_get_elem_from_raw_xml:1009}

Wed Aug 03 2022 11:13:30 +00:00 [kern_mgwd:info:2561]    snapmirror_relationship_rest.get_imp() returns: success (latency: 961.568391s) [<relationship-id>,<source_vserver>:<source_volume>,-,-,-,-,-,-,-,<destination_vserver>:<volume>,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,/api/snapmirror/relationships/<relationship-id>/,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-,-] (memory: -7188440 net, 7902568 max, 2199422456 allocated, 2206610896 freed, 14421787 allocations)