VMware Horizon Community
jmacdaddy
Enthusiast
Enthusiast
‎03-21-2016 02:41 PM

Teradici Zero (Dell P25) USB Printer Issues

I am experiencing an issue where print jobs submitted on Horizon View Windows 7 SP1 virtual desktops to USB connected printers fail part of the way through the print job.  For instance, 15 pages of a 25 page PDF document may print before showing an error in Windows.  The USB printers are two different HP models.  The endpoints are Dell P25's.  We have tested the P25s with all firmware versions from 4.5 through 5.0.2 and the issue persists.  The Horizon View Agents we have tried are 6.1.1 and 6.2.2 (ThinPrint components disabled - USB redirection only). 

The only entry of possible relevance we have seen on the P25 logs (with USB enhanced logging enabled) is:


[meta sequenceId="24794"]2016-03-08T17:21:01.90Z RC:0 URBOIP:process_request_cancel Calling transfer abort for URB req 0x3a8

(the time stamp on this log entry does not match the Agent log entries below because they are not from the same error instance)


We only started experiencing this issue after we swapped out Windows ThinPC repurposed PC endpoints with the P25s. 

We do see the following in the VMWare View Agent logs on the virtual desktops:

03/17/2016, 16:00:00.399> LVL:2 RC: 0 MGMT_PCOIP_DATA :Tx thread info: bw limit = 1366, avg tx = 0.1, avg rx = 1.7 (KBytes/s)

03/17/2016, 16:00:00.399> LVL:1 RC: 0 VGMAC :Stat frms: R=000000/000000/123633 T=001842/084643/043437 (A/I/O) Loss=0.00%/0.00% (R/T)

03/17/2016, 16:00:00.399> LVL:2 RC: 0 MGMT_PCOIP_DATA :Memory stat: available physical memory = 3575MB/6143MB

03/17/2016, 16:00:20.524> LVL:2 RC: 0 MGMT_IMG :log: cur_s 0 max_s 30 bwc 0.00 bwt 9.61 changed fps 0.1 decode rate est (MBit/sec) - 9089.93

03/17/2016, 16:00:20.524> LVL:0 RC: 0 MGMT_IMG :Imaging rtt last: 0 min: 0 max: 0 avg: 1.5618

03/17/2016, 16:00:20.524> LVL:2 RC: 0 MGMT_IMG :log: Disp_0:SoftPCoIP, Disp_1:SoftPCoIP, Disp_2:Disabled, Disp_3:Disabled

03/17/2016, 16:00:20.524> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): tbl 1 fps 0.03 quality 80

03/17/2016, 16:00:20.524> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): bits/pixel - 7.07, bits/sec - 90.49, MPix/sec - 0.00

03/17/2016, 16:00:20.524> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): fps 0.00 quality 0

03/17/2016, 16:00:20.524> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): bits/sec - 0.00, MPix/sec - 0.00, rx_pdu/sec - 0.0, tx_pdu/sec - 0.0

03/17/2016, 16:00:20.524> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): caps exceeded: 0, low_pkts: 0, pkt q: 0, slice_limited: 0, bus empty 0, total: 0.

03/17/2016, 16:00:50.524> LVL:2 RC: 0 MGMT_IMG :log: cur_s 0 max_s 30 bwc 0.00 bwt 9.61 changed fps 0.0 decode rate est (MBit/sec) - 9089.93

03/17/2016, 16:00:50.524> LVL:0 RC: 0 MGMT_IMG :Imaging rtt last: 0 min: 0 max: 0 avg: 1.5618

03/17/2016, 16:00:50.524> LVL:2 RC: 0 MGMT_IMG :log: Disp_0:SoftPCoIP, Disp_1:SoftPCoIP, Disp_2:Disabled, Disp_3:Disabled

03/17/2016, 16:00:50.524> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): tbl 1 fps 0.00 quality 80

03/17/2016, 16:00:50.524> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): bits/pixel - 0.00, bits/sec - 0.00, MPix/sec - 0.00

03/17/2016, 16:00:50.524> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): fps 0.00 quality 0

03/17/2016, 16:00:50.524> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): bits/sec - 0.00, MPix/sec - 0.00, rx_pdu/sec - 0.0, tx_pdu/sec - 0.0

03/17/2016, 16:00:50.524> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): caps exceeded: 0, low_pkts: 0, pkt q: 0, slice_limited: 0, bus empty 0, total: 0.

03/17/2016, 16:00:59.837> LVL:2 RC: 0 MGMT_PCOIP_DATA :Tx thread info: round trip time (ms) = 0, variance = 1, rto = 101, last = 1, max = 2

03/17/2016, 16:01:00.399> LVL:2 RC: 0 MGMT_PCOIP_DATA :Tx thread info: bw limit = 1366, avg tx = 0.1, avg rx = 1.8 (KBytes/s)

03/17/2016, 16:01:00.399> LVL:1 RC: 0 VGMAC :Stat frms: R=000000/000000/124317 T=001842/084645/043579 (A/I/O) Loss=0.00%/0.00% (R/T)

03/17/2016, 16:01:00.399> LVL:2 RC: 0 MGMT_PCOIP_DATA :Memory stat: available physical memory = 3578MB/6143MB

03/17/2016, 16:01:20.517> LVL:2 RC: 0 MGMT_IMG :log: cur_s 0 max_s 30 bwc 0.02 bwt 9.61 changed fps 2.5 decode rate est (MBit/sec) - 9089.93

03/17/2016, 16:01:20.517> LVL:0 RC: 0 MGMT_IMG :Imaging rtt last: 0 min: 0 max: 16 avg: 1.4328

03/17/2016, 16:01:20.517> LVL:2 RC: 0 MGMT_IMG :log: Disp_0:SoftPCoIP, Disp_1:SoftPCoIP, Disp_2:Disabled, Disp_3:Disabled

03/17/2016, 16:01:20.517> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): tbl 1 fps 2.23 quality 80

03/17/2016, 16:01:20.517> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): bits/pixel - 0.35, bits/sec - 28792.83, MPix/sec - 0.08

03/17/2016, 16:01:20.517> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): fps 0.00 quality 0

03/17/2016, 16:01:20.517> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): bits/sec - 0.00, MPix/sec - 0.00, rx_pdu/sec - 0.0, tx_pdu/sec - 0.0

03/17/2016, 16:01:20.517> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): caps exceeded: 0, low_pkts: 0, pkt q: 0, slice_limited: 0, bus empty 0, total: 0.

03/17/2016, 16:01:50.530> LVL:2 RC: 0 MGMT_IMG :log: cur_s 0 max_s 30 bwc 0.21 bwt 9.77 changed fps 14.3 decode rate est (MBit/sec) - 9089.93

03/17/2016, 16:01:50.530> LVL:0 RC: 0 MGMT_IMG :Imaging rtt last: 0 min: 0 max: 16 avg: 0.0584

03/17/2016, 16:01:50.530> LVL:2 RC: 0 MGMT_IMG :log: Disp_0:SoftPCoIP, Disp_1:SoftPCoIP, Disp_2:Disabled, Disp_3:Disabled

03/17/2016, 16:01:50.530> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): tbl 1 fps 9.39 quality 80

03/17/2016, 16:01:50.530> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): bits/pixel - 1.44, bits/sec - 263216.56, MPix/sec - 0.18

03/17/2016, 16:01:50.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): fps 0.00 quality 0

03/17/2016, 16:01:50.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): bits/sec - 0.00, MPix/sec - 0.00, rx_pdu/sec - 0.0, tx_pdu/sec - 0.0

03/17/2016, 16:01:50.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): caps exceeded: 0, low_pkts: 0, pkt q: 0, slice_limited: 0, bus empty 0, total: 0.

03/17/2016, 16:01:51.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item buffer from virtual hub, handle: 00A13770, error: 0x3e6

03/17/2016, 16:01:51.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:01:51.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item length from virtual hub handle: 00A13770, error: 0x57

03/17/2016, 16:01:51.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:01:53.592> LVL:1 RC:-500 SOFT_USB :usb_urboip_winif_complete: Vhublib_CompleteItem failed (9) for request_id 0x000019E8

03/17/2016, 16:01:53.592> LVL:1 RC:-500 SOFT_USB :usb_urboip_process_urb_completion: usb_urboip_winif_complete failed!

03/17/2016, 16:01:53.592> LVL:1 RC:-500 SOFT_USB :usb_urboip_process_rx_buffer: failed to process URB_COMPLETION

03/17/2016, 16:01:53.592> LVL:1 RC:-500 SOFT_USB :tera_usb_pkt_to_host: tera_usb_urboip_pkt_to_host() failed!

03/17/2016, 16:02:00.061> LVL:2 RC: 0 MGMT_PCOIP_DATA :Tx thread info: round trip time (ms) = 0, variance = 0, rto = 100, last = 1, max = 12

03/17/2016, 16:02:00.608> LVL:2 RC: 0 MGMT_PCOIP_DATA :Tx thread info: bw limit = 1399, avg tx = 108.6, avg rx = 17.4 (KBytes/s)

03/17/2016, 16:02:00.608> LVL:1 RC: 0 VGMAC :Stat frms: R=000000/000000/129180 T=001992/087599/047017 (A/I/O) Loss=0.00%/0.00% (R/T)

03/17/2016, 16:02:00.608> LVL:2 RC: 0 MGMT_PCOIP_DATA :Memory stat: available physical memory = 3492MB/6143MB

03/17/2016, 16:02:01.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item buffer from virtual hub, handle: 00A13770, error: 0x3e6

03/17/2016, 16:02:01.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:01.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item length from virtual hub handle: 00A13770, error: 0x57

03/17/2016, 16:02:01.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:11.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item buffer from virtual hub, handle: 00A13770, error: 0x3e6

03/17/2016, 16:02:11.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:11.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item length from virtual hub handle: 00A13770, error: 0x57

03/17/2016, 16:02:11.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:20.530> LVL:2 RC: 0 MGMT_IMG :log: cur_s 0 max_s 30 bwc 0.02 bwt 9.84 changed fps 15.7 decode rate est (MBit/sec) - 9089.93

03/17/2016, 16:02:20.530> LVL:0 RC: 0 MGMT_IMG :Imaging rtt last: 0 min: 0 max: 16 avg: 0.3495

03/17/2016, 16:02:20.530> LVL:2 RC: 0 MGMT_IMG :log: Disp_0:SoftPCoIP, Disp_1:SoftPCoIP, Disp_2:Disabled, Disp_3:Disabled

03/17/2016, 16:02:20.530> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): tbl 1 fps 12.39 quality 80

03/17/2016, 16:02:20.530> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): bits/pixel - 1.03, bits/sec - 235936.23, MPix/sec - 0.23

03/17/2016, 16:02:20.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): fps 0.00 quality 0

03/17/2016, 16:02:20.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): bits/sec - 0.00, MPix/sec - 0.00, rx_pdu/sec - 0.0, tx_pdu/sec - 0.0

03/17/2016, 16:02:20.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): caps exceeded: 0, low_pkts: 0, pkt q: 0, slice_limited: 0, bus empty 0, total: 0.

03/17/2016, 16:02:21.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item buffer from virtual hub, handle: 00A13770, error: 0x3e6

03/17/2016, 16:02:21.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:21.108> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item length from virtual hub handle: 00A13770, error: 0x57

03/17/2016, 16:02:21.108> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:31.113> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item buffer from virtual hub, handle: 00A13770, error: 0x3e6

03/17/2016, 16:02:31.113> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:31.113> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item length from virtual hub handle: 00A13770, error: 0x57

03/17/2016, 16:02:31.113> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:41.113> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item buffer from virtual hub, handle: 00A13770, error: 0x3e6

03/17/2016, 16:02:41.113> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:41.113> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item length from virtual hub handle: 00A13770, error: 0x57

03/17/2016, 16:02:41.113> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:50.530> LVL:2 RC: 0 MGMT_IMG :log: cur_s 0 max_s 30 bwc 0.07 bwt 9.84 changed fps 10.6 decode rate est (MBit/sec) - 9089.93

03/17/2016, 16:02:50.530> LVL:0 RC: 0 MGMT_IMG :Imaging rtt last: 0 min: 0 max: 16 avg: 2.0133

03/17/2016, 16:02:50.530> LVL:2 RC: 0 MGMT_IMG :log: Disp_0:SoftPCoIP, Disp_1:SoftPCoIP, Disp_2:Disabled, Disp_3:Disabled

03/17/2016, 16:02:50.530> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): tbl 1 fps 6.03 quality 80

03/17/2016, 16:02:50.530> LVL:2 RC: 0 MGMT_IMG :log (SoftIPC): bits/pixel - 0.85, bits/sec - 183127.87, MPix/sec - 0.22

03/17/2016, 16:02:50.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): fps 0.00 quality 0

03/17/2016, 16:02:50.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): bits/sec - 0.00, MPix/sec - 0.00, rx_pdu/sec - 0.0, tx_pdu/sec - 0.0

03/17/2016, 16:02:50.530> LVL:2 RC: 0 MGMT_IMG :log (Tera2800IPC): caps exceeded: 0, low_pkts: 0, pkt q: 0, slice_limited: 0, bus empty 0, total: 0.

03/17/2016, 16:02:51.123> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item buffer from virtual hub, handle: 00A13770, error: 0x3e6

03/17/2016, 16:02:51.123> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)

03/17/2016, 16:02:51.123> LVL:1 RC: 0 SOFT_USB :VHUBLIB(error): Failed to get item length from virtual hub handle: 00A13770, error: 0x57

03/17/2016, 16:02:51.123> LVL:1 RC:-500 SOFT_USB :process_urbs: Vhublib_GetNextItem failed! (9)


Any help would be greatly appreciated.

0 Kudos
4 Replies
TheNuts
Contributor
Contributor
‎07-07-2016 08:15 AM

Did you ever resolve this?  Reason I ask, is I just did a Google search on the term "Vhublib_GetNextItem" and this discussion came up. 

We were having issues using the latest View 6.2.2 agent with Imprivata OneSign and attached USB badge readers.  Every time a user would badge tap to disconnect from the View desktop, the View Agent would crash.  Removing USB redirection from the View agent fixed the issue however that was not acceptable since we have users using Nuance Dragon with USB microphones.

After several weeks going around with both Imprivata and VMware engineering, it was determined it was the VMware agent causing the issue.  VMware Engineering gave us a new build of the 6.2.2 agent and so far no issues.  VMware Engineering stated this build of the View agent "contains a fix for a double free glitch with  a "Vhublib_GetNextItem" function."

I am not sure  if your issue is fixed or not but thought I would provide the fix that worked in our situation.  We are not using Zero Clients (yet) but are using re-purposed Windows PCs.

0 Kudos
GregStr
Contributor
Contributor
‎09-13-2016 01:49 PM

We are having the same issue. Could you share which build number of the View 6.2.2 Agent VMware provided you with? We plan on disabling USB redirection tonight and test tomorrow. Also, I see in your future posts that you have moved to Horizon 7. Did that make any difference to the initial issue? Thanks in advance!

0 Kudos
jmacdaddy
Enthusiast
Enthusiast
‎09-15-2016 10:55 AM

We tested with 7.0.1 and 7.0.0 with no joy.  TheNuts mentioned a specially fixed 6.2.2 Agent that worked for him.  I would like to know if this fix was included in any of the 7.0 Agents (including 7.0.2 that dropped today).  To get around this problem we took the USB printers away from our power users and gave them low-end networked printers.

0 Kudos
TheNuts
Contributor
Contributor
‎09-16-2016 03:16 AM

The build was 6.2.2-3691463.  Engineering said the fix would be in the View 6.3 agent and the &.x agents.

0 Kudos