Search Engine: Elastic

Article ID: 129298, created on Aug 22, 2016, last review on Aug 22, 2016

  • Applies to:
  • Operations Automation


Task fails with the output:

    Enable WebMatrix Publishing for virtual web server <ID> on host '<FQDN>' (host_id=<HW_ID>, sub_id=<SUB_ID>, domain=s<DOM_ID>.instanturl.tld, w_id=<IIS_WEBSPACE_ID>). failed with timeout error.
    Request has been timed out, details:
    system exception, ID ''
    TAO exception, minor code = 3e (timeout during recv; low 7 bits of errno: 62 Timer expired), completed = MAYBE


Intermediate network equipment between OA MN and WPE terminates the connection prematurely without notifying either ends.


Fix the network equipment to allow long network connections with no data exchange.

As an alternative way, analyze why the WPE task takes so long to be finished and decrease the exectution time.

Another possible preventive measure is changing OS TCP keepalive settings to send keepalive probes sooner than the default 2 hours. Linux TCP keepalive documentation:
TCP Keepalive HOWTO

Troubleshooting example

  1. After launching the task, check the connection that gets established from OA MN to WPE, a new client port (36241) is allocated on MN side. Start to monitor the state of the connection with netstat:

    #  while true; do date; netstat -antp | grep | grep 36241 ; sleep 60 ; done

    It provides the snapshots of the output each minute, the presence of the entries confirms that the connection is established:

    Sat Apr 30 16:51:30 EDT 2016
    tcp        0      0              ESTABLISHED 13685/SoLoader
    Sat Apr 30 16:52:30 EDT 2016
    tcp        0      0              ESTABLISHED 13685/SoLoader
    Sat Apr 30 16:53:31 EDT 2016
    tcp        0      0              ESTABLISHED 13685/SoLoader
  2. The same thing should be done on WPE host (in Powershell):

    PS C:\> while ($true) {date; netstat -ano | findstr | findstr 36241 ; sleep 60}

    The example below shows that the connection is already dropped at 4:39 PM:

    Saturday, April 30, 2016 4:37:27 PM
      TCP        ESTABLISHED     4
    Saturday, April 30, 2016 4:38:27 PM
      TCP        ESTABLISHED     4
    Saturday, April 30, 2016 4:39:27 PM
    Saturday, April 30, 2016 4:40:27 PM
    Saturday, April 30, 2016 4:41:27 PM
  3. 16:39 is the time, when WPE request finished its execution per WPE logs:

    Find the start of the request execution and fetch the thread ID (in brackets):

    PS C:\> select-string webmatrix wpe.log
    wpe.log:256487:DEBUG    2016-04-30 15:00:10 (352/5108): Request summary: Enable WebMatrix Publishing for virtual web server 19082 on host '' (host_id=1010, sub_id=1010101,, w_id=321231).

    Search the ending of this thread ID:

    PS C:\> select-string "352/5108" wpe.log
    wpe.log:302061:DEBUG    2016-04-30 15:01:38 (352/5108): Call method "File System Provider::SetDirectoryAttributes"
    wpe.log:302062:INFO    2016-04-30 15:01:38 (352/5108): Procedure "File System Provider::SetDirectoryAttributes" - (ENTER)
    wpe.log:302063:DEBUG    2016-04-30 15:01:38 (352/5108): Inheritance not changed
    wpe.log:443201:INFO    2016-04-30 16:39:11 (352/5108): Procedure "File System Provider::SetDirectoryAttributes" - (EXIT)
    wpe.log:443742:INFO    2016-04-30 16:39:11 (352/5108): ----- REQUEST cb428dff-9909-4ca8-a825-d1711203433b is finished
    wpe.log:443743:DEBUG    2016-04-30 16:39:11 (352/5108): Request from is handled.
  4. The above outputs mean that the connection got terminated somewhere between OA MN and WPE without notifying either ends, and, as a result, OA MN did not receive any data at all, so the connection remains alive, while WPE sent its final portion of data, having closed the connection.

5356b422f65bdad1c3e9edca5d74a1ae caea8340e2d186a540518d08602aa065 e12cea1d47a3125d335d68e6d4e15e07

Email subscription for changes to this article
Save as PDF