8 Replies Latest reply: Jul 13, 2013 4:36 AM by jolocktest RSS

    VMware USB Arbitration Service bug

    Minaum Lurker

      Hello!

       

      VMware Workstation v8.0.x (all versions), VMware Workstation v9.0.0 and VMware Workstation v9.0.1 have the same bug in USB Arbitration Service.

       

      I have a few error messages in debug log of USB Arbitration Service. This service try to do something with USB every second, and always fail. All these errors are stored to the debug log, it is writing, writing, writing and writing this errors to the log, again, again, and again. My logs have a very huge size - 231MB (vmware-usbarb-3384.log), 236MB (vmware-usbarb-3512.log), 479MB (vmware-usbarb-3036.log) and so on. Moreover, vmware-usbarbitrator.exe process (service) acquiring this virtual memory to store all log in the memory!!! I.e. it seems like a permanent memory leak, but really, it actively store new errors to the log. Please fix this bug with USB.

       

      Here is a log in %TEMP%: vmware-usbarb-XXXX.log

      ===================================================================================

      2012-11-25T14:59:46.736+04:00| usbArb| I120: Log for VMware USB Arbitration Service pid=15996 version=5.0.1 build=build-871296 option=Release
      2012-11-25T14:59:46.736+04:00| usbArb| I120: The process is 32-bit.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: Host codepage=windows-1251 encoding=windows-1251
      2012-11-25T14:59:46.736+04:00| usbArb| I120: Host is Windows Server 2003 Enterprise Edition Service Pack 2 (Build 3790)
      2012-11-25T14:59:46.736+04:00| usbArb| I120: VTHREAD initialize main thread 2 "usbArb" host id 12712
      2012-11-25T14:59:46.736+04:00| usbArb| I120: Msg_Reset:
      2012-11-25T14:59:46.736+04:00| usbArb| I120: [msg.dictionary.load.openFailed] Cannot open file "C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\config.ini": The system cannot find the file specified.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: ----------------------------------------
      2012-11-25T14:59:46.736+04:00| usbArb| I120: PREF Optional preferences file not found at C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\config.ini. Using default values.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: Msg_Reset:
      2012-11-25T14:59:46.736+04:00| usbArb| I120: [msg.dictionary.load.openFailed] Cannot open file "C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\settings.ini": The system cannot find the file specified.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: ----------------------------------------
      2012-11-25T14:59:46.736+04:00| usbArb| I120: PREF Optional preferences file not found at C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\settings.ini. Using default values.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: Msg_Reset:
      2012-11-25T14:59:46.736+04:00| usbArb| I120: [msg.dictionary.load.openFailed] Cannot open file "C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\config.ini": The system cannot find the file specified.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: ----------------------------------------
      2012-11-25T14:59:46.736+04:00| usbArb| I120: PREF Optional preferences file not found at C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\config.ini. Using default values.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: Msg_Reset:
      2012-11-25T14:59:46.736+04:00| usbArb| I120: [msg.dictionary.load.openFailed] Cannot open file "C:\Documents and Settings\Default User\Application Data\VMware\config.ini": The system cannot find the file specified.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: ----------------------------------------
      2012-11-25T14:59:46.736+04:00| usbArb| I120: PREF Optional preferences file not found at C:\Documents and Settings\Default User\Application Data\VMware\config.ini. Using default values.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: PREF Disabling user preferences because disableUserPreferences is set.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: PREF Failed to load user preferences.
      2012-11-25T14:59:46.736+04:00| usbArb| I120: POLL Using the select API Implementation for PollDefault
      2012-11-25T14:59:46.736+04:00| usbArb| I120: Hostinfo_OpenProcessBits: OpenProcess access bits are 400.
      2012-11-25T14:59:46.783+04:00| usbArb| I120: DICT --- USER PREFERENCES
      2012-11-25T14:59:46.783+04:00| usbArb| I120: DICT --- USER DEFAULTS C:\Documents and Settings\Default User\Application Data\VMware\config.ini
      2012-11-25T14:59:46.783+04:00| usbArb| I120: DICT --- HOST DEFAULTS C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\config.ini
      2012-11-25T14:59:46.783+04:00| usbArb| I120: DICT --- SITE DEFAULTS C:\Documents and Settings\All Users\Application Data\VMware\VMware USB Arbitration Service\config.ini
      2012-11-25T14:59:46.783+04:00| usbArb| I120: VMware USB Arbitration Service Version 10.1.23
      2012-11-25T14:59:46.783+04:00| vthread-3| I120: VTHREAD initialize thread 3 "vthread-3" host id 16000
      2012-11-25T14:59:46.783+04:00| vthread-3| I120: USBArb: Starting VMUSBArbService args:'VMUSBArbService'
      2012-11-25T14:59:46.783+04:00| vthread-3| I120: USBGW: Host controller #0 = "\\?\HCD0"
      2012-11-25T14:59:46.783+04:00| vthread-3| I120: USBGW: Host controller #1 = "\\?\HCD1"
      2012-11-25T14:59:46.783+04:00| vthread-3| I120: USBGW: Host controller #2 = "\\?\pci#ven_1b21&dev_1042&subsys_84881043&rev_00#4&39d38640&0&00e2#{3abf6f2d-71c4-462a-8a92-1e6861e6af27}"
      2012-11-25T14:59:46.783+04:00| vthread-3| I120: USBGW: Host controller #3 = "\\?\pci#ven_1b21&dev_1042&subsys_84881043&rev_00#4&2a3c25e0&0&00e3#{3abf6f2d-71c4-462a-8a92-1e6861e6af27}"
      2012-11-25T14:59:46.783+04:00| vthread-3| I120: USBArb: Connected to HCMON version 3.16
      2012-11-25T14:59:46.783+04:00| vthread-3| W110: USBArb: Failed to send HC NamC:\??\pci#ven_1b21&dev_1042&subsys_84881043&rev_00#4&39d38640&0&00e2#{3abf6f2d-71c4-462a-8a92-1e6861e6af27} to HCMON: A device attached to the system is not functioning (31)
      2012-11-25T14:59:46.783+04:00| vthread-3| W110: USBArb: Failed to send HC NamC:\??\pci#ven_1b21&dev_1042&subsys_84881043&rev_00#4&2a3c25e0&0&00e3#{3abf6f2d-71c4-462a-8a92-1e6861e6af27} to HCMON: A device attached to the system is not functioning (31)
      2012-11-25T14:59:46.892+04:00| vthread-4| I120: VTHREAD initialize thread 4 "vthread-4" host id 15304
      2012-11-25T14:59:46.892+04:00| vthread-4| I120: HOSTINFO 1090789854562 @ 3579545Hz -> 0 @ 1000000000Hz
      2012-11-25T14:59:46.892+04:00| vthread-4| I120: HOSTINFO ((x * 2343484437) >> 23) + -304728632951204
      2012-11-25T14:59:46.908+04:00| vthread-4| I120: USBArb: VMUSBArbService Started.
      2012-11-25T14:59:48.908+04:00| vthread-4| I120: USBGW: Error retrieving child name: The request is not supported (50)
      2012-11-25T14:59:48.908+04:00| vthread-4| W110: USBGW-ENUM: Failed to get hub name for port:2
      2012-11-25T14:59:48.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:1. Leaving out of enum
      2012-11-25T14:59:48.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:2. Leaving out of enum
      2012-11-25T14:59:48.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:3. Leaving out of enum
      2012-11-25T14:59:48.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:4. Leaving out of enum
      2012-11-25T14:59:48.923+04:00| vthread-4| I120: USBGW: Error retrieving child name: The request is not supported (50)
      2012-11-25T14:59:48.923+04:00| vthread-4| W110: USBGW-ENUM: Failed to get hub name for port:2
      2012-11-25T14:59:49.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:1. Leaving out of enum
      2012-11-25T14:59:49.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:2. Leaving out of enum
      2012-11-25T14:59:49.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:3. Leaving out of enum
      2012-11-25T14:59:49.923+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:4. Leaving out of enum
      2012-11-25T14:59:49.923+04:00| vthread-4| I120: USBGW: Error retrieving child name: The request is not supported (50)
      2012-11-25T14:59:49.923+04:00| vthread-4| W110: USBGW-ENUM: Failed to get hub name for port:2

       

      [... skipped about 5 mb of the same content ...]

       

      2012-11-25T17:16:47.653+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:1. Leaving out of enum
      2012-11-25T17:16:47.653+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:2. Leaving out of enum
      2012-11-25T17:16:47.653+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:3. Leaving out of enum
      2012-11-25T17:16:47.653+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:4. Leaving out of enum
      2012-11-25T17:16:47.653+04:00| vthread-4| I120: USBGW: Error retrieving child name: The request is not supported (50)
      2012-11-25T17:16:47.653+04:00| vthread-4| W110: USBGW-ENUM: Failed to get hub name for port:2
      2012-11-25T17:16:48.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:1. Leaving out of enum
      2012-11-25T17:16:48.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:2. Leaving out of enum
      2012-11-25T17:16:48.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:3. Leaving out of enum
      2012-11-25T17:16:48.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:4. Leaving out of enum
      2012-11-25T17:16:48.654+04:00| vthread-4| I120: USBGW: Error retrieving child name: The request is not supported (50)
      2012-11-25T17:16:48.654+04:00| vthread-4| W110: USBGW-ENUM: Failed to get hub name for port:2
      2012-11-25T17:16:49.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:1. Leaving out of enum
      2012-11-25T17:16:49.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:2. Leaving out of enum
      2012-11-25T17:16:49.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:3. Leaving out of enum
      2012-11-25T17:16:49.654+04:00| vthread-4| I120: USBGW_ENUM: Couldn't get instanceId from topology:0x3000000 port:4. Leaving out of enum
      2012-11-25T17:16:49.654+04:00| vthread-4| I120: USBGW: Error retrieving child name: The request is not supported (50)
      2012-11-25T17:16:49.654+04:00| vthread-4| W110: USBGW-ENUM: Failed to get hub name for port:2

      ===================================================================================

        • 1. Re: VMware USB Arbitration Service bug
          continuum Guru User Moderators vExpert

          do you have USB 3 hardware on your host ? - USB3 support is work in progress and only works with a few drivers at the moment

          • 2. Re: VMware USB Arbitration Service bug
            Minaum Lurker

            No, I have not.

             

            There are few devices, that are connected through USB: simple Microsoft Keyboard, simple A4Tech mouse, an old Transcend USB Flash and an old D-Link ADSL USB Modem. All these devices are USB 1.0/1.1/2.0, not a 3.0 for 100%. Also, they are plugged to USB 2.0 connectors, not USB 3.0.

            • 3. Re: VMware USB Arbitration Service bug
              Minaum Lurker

              Could someone forward this to developers? Because it is a real bug:

              * permanently growing a log with the same error messages (the best thing it is to fix the issue, to have no that error messages or find workaround for them)

              * and permanently growing used Virtual Memory for USB Arbitrator Service process = this behaviour is similar to memory leak, but there is is known why it occurs -- growing log with errors.

              • 4. Re: VMware USB Arbitration Service bug
                BrianTokyo Lurker

                Same issue here, after a few days the service is already using over 1GB of ram.

                • 5. Re: VMware USB Arbitration Service bug
                  zacwolfdotcom Lurker

                  I am seeing this issue as well, and it pretty much equates to a memory leak because within a short-time of firing up an appliance, the "VMWARE USB Arbitration" services consumes over a gig of memory...

                   

                  I do have an additional USB3 pci-e card [is there any information regarding currently supported drivers?].

                   

                  Is there any workaround to disable logging for the service until support is implemented?

                   

                  My log file is filled with:

                   

                  2013-04-10T17:45:40.403-04:00| vthread-4| I120: USBGW_ENUM: Got invalid dd for topology:0x3000000 port:4. Leaving out of enum

                  • 6. Re: VMware USB Arbitration Service bug
                    zacwolfdotcom Lurker

                    OK, after researching this further, it looks like the root cause was I had a faulty USB device driver ("for topology:0x3000000 port:4") on my system OS (not the guest OS).  I am running Windows 8-64bit and WMware Workstation 9 with all latest patches.

                     

                    I deleted the device from the Device Manager, re-installed with a good driver, and the error messages stopped.

                     

                    BUT, this does still point to a very serious flaw in the "VMware USB Abritration Service" code, in that it would seem that the log output is being retained in memory as well as output to the log file?  This quickly creates what equates to a memory leak issue, when log entries are being created over and over and over again.

                     

                    This service needs to be fixed to not "cache" the log output in memory, and/or to ignore errors after X-number of repeats.

                     

                    THANKS!

                    -Zac Morris

                    • 7. Re: VMware USB Arbitration Service bug
                      jolocktest Lurker

                      dose any one no how to fix this because it is bull**** and i hate it because i boght it

                      • 8. Re: VMware USB Arbitration Service bug
                        jolocktest Lurker

                        Select the ‘Start’ button, in the ‘search programs and files’ box, type ‘regedit.exe’
                        -Navigate the registry to this entry:
                        HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Class\{36FC9E60-C465-11CF-8056-444553540000}.
                        In the right hand side, if the value “UpperFilters” exists, delete it.
                        http://mooremn.files.wordpress.com/2010/06/vmwareusbarbsvc06-upprfiltr.jpg?w=593

                        5. Reboot the system so that VMWare can access USB devices.

                        IT WORKS TRUST ME IT THE ONLY WAY IF YOU WANT TO THANK ME SUBSCRIB TO MY YOU TUBE CHEANLE jake Bradford - YouTube PLZ DO IT IT TOOK ME HOURS FINDING OUT THIS HOPE IT HELPS