Pages

Sunday, June 7, 2020

Event ID 3001 Error constantly logged on Citrix Cloud Connectors after FortiOS upgrade to 6.2.3 causing virtual desktop connectivity issues

Problem

You’ve just recently upgraded the FortiOS of a FortiGate 600D to version 6.2.3 and began to experience connectivity issues to a Citrix Virtual Apps and Desktops 1909 environment where users are unable to connect to desktops and receive the following error:

Cannot start desktop “Desktop Name”.

image

Desktops in the Citrix Studio also show that the VDA agents would suddenly become unregistered and later registered again but regardless of their state, brokered sessions fail majority of the time.

Errors on Citrix Cloud Connector Servers

Logging onto the Citrix Cloud Connectors reveal that the following event ID is constantly logged every 5 to 7 minutes:

Log Name: Application

Source: Citrix Remote Broker Provider

Event ID: 3001

Level: Error

User: NETWORK SERVICE

HA Mode Checking Start - component Broker Proxy has reported a failure with reason = Received: HAModeException - No WebSocket channels are available. (Target url: contoso.xendesktop.net/Citrix/XaXdProxy/)

image

image

Log Name: Application

Source: Citrix Remote Broker Provider

Event ID: 3001

Level: Error

User: NETWORK SERVICE

HA Mode Checking Start - component XmlServicesPlugin has reported a failure with reason = The underlying connection was closed: An unexpected error occurred on a receive.(Target Url: https://contoso.xendesktop.net/scripts/wpnbr.dll)

image

Running the Cloud Connector Connectivity Check utility from: https://support.citrix.com/article/CTX260337

image

Will show inconsistent results where various URLs will fail at different times:

image

Performing Wireshark on the Citrix Cloud Connectors will reveal that there are a lot of connection resets between the Citrix Cloud and the Cloud Connectors.

A short trace of 229 packets using filter ip.addr eq 20.41.61.15 and tcp.analysis.flags, reveals that 66 packets are TCP retransitions equating to almost 29% with and 12 TCP resets coming from connector.

**Note that the 20.41.61.15 IP resolves to the URL that the Citrix Cloud Connector is having issues connecting to.

image

Errors on Citrix StoreFront Servers

Logging onto the Citrix StoreFront servers will reveal the following events constantly logged repetitive:

image

Log Name: Citrix Delivery Services

Source: Citrix Store Service

Event ID: 4011

Level: Information

User: N/A

The Citrix XML Service at address citrixcloud1.contoso.com:80 has passed the background health check and has been restored to the list of active services.

image

Log Name: Citrix Delivery Services

Source: Citrix Store Service

Event ID: 0

Level: Error

User: N/A

The Citrix servers sent HTTP headers indicating that an error occurred: 500 Internal Server Error. This message was reported from the XML Service at address http://citrixcloud2.contoso.com/scripts/wpnbr.dll [NFuseProtocol.TRequestAddress]. The specified Citrix XML Service could not be contacted and has been temporarily removed from the list of active services.

image

**The above error will cycle through all of the Citrix Cloud Connectors.

Log Name: Citrix Delivery Services

Source: Citrix Store Service

Event ID: 4003

Level: Error

User: N/A

All the Citrix XML Services configured for farm Cloud failed to respond to this XML Service transaction.

image

Log Name: Citrix Delivery Services

Source: Citrix Store Service

Event ID: 28

Level: Warning

User: N/A

Failed to launch the resource 'Cloud.Workspace $S32-61' using the Citrix XML Service at address 'http://citrixcloud1.contoso.com/scripts/wpnbr.dll'. All the Citrix XML Services configured for farm Cloud failed to respond to this XML Service transaction.

com.citrix.wing.SourceUnavailableException, PublicAPI, Version=3.12.0.0, Culture=neutral, PublicKeyToken=null

All the Citrix XML Services configured for farm Cloud failed to respond to this XML Service transaction.

at com.citrix.wing.core.mpssourceimpl.MPSFarmFacade.GetAddress(Context ctxt, String appName, String deviceId, String clientName, Boolean alternate, MPSAddressingType requestedAddressType, String friendlyName, String hostId, String hostIdType, String sessionId, NameValuePair[] cookies, ClientType clientType, String retryKey, LaunchOverride launchOverride, Nullable`1 isPrelaunch, Nullable`1 disableAutoLogoff, Nullable`1 tenantId, String anonymousUserId)

at com.citrix.wing.core.mpssourceimpl.MPSLaunchImpl.GetAddress(Context env, String appName, String deviceId, String clientName, Boolean alternate, MPSAddressingType requestedAddressType, String friendlyName, String hostId, String hostIdType, String sessionId, NameValuePair[] cookies, ClientType clientType, String retryKey, LaunchOverride launchOverride, Nullable`1 isPrelaunch, Nullable`1 disableAutoLogoff, Nullable`1 tenantId, String anonymousUserId)

at com.citrix.wing.core.mpssourceimpl.MPSLaunchImpl.LaunchRemoted(Dictionary`2 parameters, Context env, AppLaunchParams appLaunchParams)

at com.citrix.wing.core.mpssourceimpl.MPSLaunchImpl.Launch(Dictionary`2 parameters, Context env, AppLaunchParams appLaunchParams)

at com.citrix.wing.core.applyaccessprefs.AAPLaunch.Launch(Dictionary`2 parameters, Context env, AppLaunchParams appLaunchParams)

at com.citrix.wing.core.clientproxyprovider.CPPLaunch.Launch(Dictionary`2 parameters, Context env, AppLaunchParams appLaunchParams)

at com.citrix.wing.core.connectionroutingprovider.CRPLaunch.LaunchInternal(Dictionary`2 parameters, Context env, AppLaunchParams appLaunchParams, Boolean useAlternateAddress)

at com.citrix.wing.core.connectionroutingprovider.CRPLaunch.Launch(Dictionary`2 parameters, Context env, AppLaunchParams appLaunchParams)

at com.citrix.wing.core.bandwidthcontrolprovider.BCPLaunch.Launch(Dictionary`2 parameters, Context env, AppLaunchParams appLaunchParams)

at Citrix.DeliveryServices.ResourcesCommon.Wing.WingAdaptors.OverrideIcaFileLaunch.Launch(Dictionary`2 launchParams, Context env, AppLaunchParams appLaunchParams)

at Citrix.DeliveryServices.ResourcesCommon.Wing.WingAdaptors.LaunchUtilities.IcaLaunch(IRequestWrapper request, Resource resource, LaunchSettings launchSettings, String retryKey)

com.citrix.wing.core.xmlclient.types.WireException, Private, Version=3.12.0.0, Culture=neutral, PublicKeyToken=null

HttpErrorPacket(500,Internal Server Error)

at com.citrix.wing.core.xmlclient.transactions.TransactionTransport.handleHttpErrorPacket(Int32 httpErrorStatus, String httpReasonPhrase)

at com.citrix.wing.core.xmlclient.transactions.CtxTransactionTransport.receiveTransportHeaders()

at com.citrix.wing.core.xmlclient.transactions.CtxTransactionTransport.receiveResponsePacketImpl(XmlMarshall marshaller)

at com.citrix.wing.core.xmlclient.transactions.ParsedTransaction.sendAndReceiveXmlMessage(XmlMessage request, AccessToken accessToken)

at com.citrix.wing.core.xmlclient.transactions.nfuse.NFuseProtocolTransaction.SendAndReceiveSingleNFuseMessage[TRequest,TResponse](TRequest request, AccessToken accessToken)

at com.citrix.wing.core.xmlclient.transactions.nfuse.AddressTransaction.TransactImpl()

at com.citrix.wing.core.xmlclient.transactions.ParsedTransaction.Transact()

at com.citrix.wing.core.mpssourceimpl.MPSFarmFacade.GetAddress(Context ctxt, String appName, String deviceId, String clientName, Boolean alternate, MPSAddressingType requestedAddressType, String friendlyName, String hostId, String hostIdType, String sessionId, NameValuePair[] cookies, ClientType clientType, String retryKey, LaunchOverride launchOverride, Nullable`1 isPrelaunch, Nullable`1 disableAutoLogoff, Nullable`1 tenantId, String anonymousUserId)

image

Errors on VDAs (Virtual Desktop Agents / VDIs)

Logging directly onto the VDAs will reveal many warnings and errors related to the Citrix Cloud Connector connectivity:

Log Name: Application
Source: Citrix Desktop Service

Event ID: 1014

Level: Warning

The Citrix Desktop Service lost contact with the Citrix Desktop Delivery Controller Service on server ‘citrixcloud1.contoso.com’. The service will now attempt to register again.

image

Citrix Cloud Connectors

Review the Cloud Connector connectivity via the Citrix portal will show the cloud connectors with warnings at times and green at other times.

image

Running a Run Health Check will take more than expected and while it completes, the status of the connector may or may not indicate the last checked date.

image

Citrix Cloud Backend Logs

Opening a ticket with Citrix Support and having the engineer review the backend Citrix Cloud connections will reveal an abnormal amount of disconnects. The following was the report we received:

13k events related to Connected/Disconnected/ConnectingFailed in the past 24 hours

038041d1-acac-4903-b88a-817b312f2a1c = citrixcloud2.contoso.com 2270 events disconnected

0812a411-754e-4b03-a6cf-382764a63a6 = citrixcloud3.contoso.com 1782 events disconnected

5ebc62a9-a015-492a-81dd-ceb649fda8f3 citrixcloud1.contoso.com 2508 for disconnected

image

Solution

This issue took quite a bit of time to resolve as the FortiOS upgrade to 6.2.3 was completed 2 weeks prior to the virtual desktop connectivity issues to begin so it was the last place I thought would be the problem. After eliminating every single possibility that there was something wrong with the Citrix environment, I asked the network engineer to open up a ticket with Fortinet to see if they can perform a more in depth tracing for the packets sent and received between the firewall and the Citrix Cloud. To our surprise, the Fortinet engineer who finally gave us a call back immediately indicated that we may be experiencing a bug in the FortiOS 6.2.3, which could cause such an issue. The following are the messages we received from the support engineer:

I informed you that, as you have SSO in your config, you could be very well hitting the known issue for internal servers due session being deleted. We will need to run the flow trace at time of disconnect, so that we can confirm the behavior.

We got on a call with the engineer and was able to determine that it was indeed a bug in this version of the FortiOS. The recommended remediation was to upgrade to either a special build of 6.2.3 that addressed this issue or upgrade to 6.2.4. We ended up upgrading to the 6.2.3 build8283 (GA) which resolved our issue.

image

For those who are interested, the following is the case summary the engineer provided:

1) We discussed the citrix applications were hanging for a prolong period.

2) FGT is currently running the firmware version 6.2.3 and the Citrix server 20.41.61.15 is accessed on the port 443

3) We checked the session list for one of the machines reporting the issue 192.168.5.71 session info: proto=6 proto_state=01 duration=269 expire=268 timeout=300 flags=00000000 sockflag=00000000 sockport=0 av_idx=0 use=5 origin-shaper= reply-shaper=high-priority prio=2 guarantee 0Bps max 134217728Bps traffic 5525Bps drops 0B per_ip_shaper= class_id=0 shaping_policy_id=6 ha_id=0 policy_dir=0 tunnel=/ vlan_cos=0/255 user=MROGERS auth_server=BCAUTH state=log may_dirty npu rs f00 acct-ext statistic(bytes/packets/allow_err): org=30896/83/1 reply=35645/59/1 tuples=2 tx speed(Bps/kbps): 114/0 rx speed(Bps/kbps): 132/1 orgin->sink: org pre->post, reply pre->post dev=11->25/25->11 gwy=198.182.170.1/192.168.5.71 hook=post dir=org act=snat 192.168.5.71:58467->20.41.61.15:443(198.182.170.253:58467) hook=pre dir=reply act=dnat 20.41.61.15:443->198.182.170.253:58467(192.168.5.71:58467) pos/(before,after) 0/(0,0), 0/(0,0) src_mac=00:50:56:b0:c1:53 misc=0 policy_id=213 auth_info=0 chk_client_info=0 vd=0 serial=0a35b6a8 tos=ff/ff app_list=0 app=0 url_cat=0 rpdb_link_id = ff000001 ngfwid=n/a dd_type=0 dd_mode=0 npu_state=0x000c00 npu info: flag=0x81/0x81, offload=8/8, ips_offload=0/0, epid=154/140, ipid=140/154, vlan=0x0000/0x0000 vlifid=140/154, vtag_in=0x0000/0x0000 in_npu=1/1, out_npu=1/1, fwd_en=0/0, qid=7/0

4) In the diagnose firewall auth list we could see the source 192.168.1.57 BC-CC-600D-FW01 # diagnose firewall auth list 192.168.5.71, MROGERS type: fsso, id: 0, duration: 559, idled: 0 server: BCAUTH packets: in 2254 out 2034, bytes: in 933560 out 856864 group_id: 4 33554905 33554989 33555163 33555200 33555204 33555203 33555198 33554433 group_name: ALL_BC_AD_USERS CN=OPERATIONS,OU=DISTRIBUTION GROUPS,OU=GROUPS,DC=CONTOSO,DC=COM CN=SECURITY DEPT,OU=SECURITY,OU=OFFICEADMIN,DC=CONTOSO,DC=COM CN=WIRELESSACCESS,OU=SECURITY GROUPS,OU=GROUPS,DC=CONTOSO,DC=COM CN=TESTALLEMPLOYEES,OU=DISTRIBUTION GROUPS,OU=GROUPS,DC=CONTOSO,DC=COM CN=ALL EMPLOYEES,OU=DISTRIBUTION GROUPS,OU=GROUPS,DC=CONTOSO,DC=COM CN=ALLEMPLOYEES,OU=DISTRIBUTION GROUPS,OU=GROUPS,DC=CONTOSO,DC=COM CN=ALLSUPPORTSTAFF,OU=DISTRIBUTION GROUPS,OU=GROUPS,DC=CONTOSO,DC=COM CN=Domain Users,CN=Users,DC=CONTOSO,DC=COM

5) Further in the debug flow we could see the msg="no session matched" 2020-06-06 18:49:56 id=20085 trace_id=55 func=print_pkt_detail line=5501 msg="vd-root:0 received a packet(proto=6, 192.168.5.71:57775->20.41.61.15:443) from port12. flag [.], seq 1161501577, ack 1787291322, win 255" 2020-06-06 18:49:56 id=20085 trace_id=55 func=vf_ip_route_input_common line=2581 msg="Match policy routing id=2133000193: to 20.41.61.15 via ifindex-25" 2020-06-06 18:49:56 id=20085 trace_id=55 func=vf_ip_route_input_common line=2596 msg="find a route: flag=04000000 gw-198.182.170.1 via port18" 2020-06-06 18:49:56 id=20085 trace_id=55 func=fw_forward_dirty_handler line=385 msg="no session matched"

6) As discussed, we have a know issue of RDP and other applications freezing due to no session match error Bug Id ==> 0605950

7) It seems that when the authed session is changed it clears the non-auth session for the same Ip.

8) The issue is resolved in the newer firmware version 6.2.4. 9) You did not want to upgrade to 6.2.4 so we do have a special build 8283 that resolves this issue. Please upgraded the firmware to this attached build and let us know.

No comments: