Dear all,
Warm Greetings to all fellow VDI and SunRay users

Sorry for a long post and a little history .
I have finally took the courages step and upgraded to VDI 3.3
We'd have been happily running on VDI3.1 for some time.
However, all the improvements seem to be pointing towards an upgrade path
Upgrade to 3.2 and then to 3.3 did not work out as expected, so I backed up
the store data and the database and  choose a clean install.
We are a small department and everything is served off very Powerful
Sun x4600 M2 server with 120 GB of ram. All the SunRays are 2FS Units.

2009
Next month there will be 2 years since we moved into production and I was 
giving a presentation to the department, showing off to users seamless mounting 
of USB drives under Ubuntu Linux with any file systems that Ubuntu supported
At this time  it was not supported by the VirtualBox server running on Solaris 
x86 and neither it was supported by VDI 3.0
A little hack did the trick. A bit later I have also added XP and Win7 which  
worked as a charm with nearly all USB keys. The only reason we went into full 
production and managed to get finances for updates and support was that I made 
to work:  Linux +USB, using software that was not supporting this. The fact 
that Windows Guests worked as well was just a bonus. No extra drivers were 
used but just the guest additions.

2011

I install 3.3, imported previously exported desktops ( exported with VDI3.1)
recreated the store.
Very positive experience and it seem that everything worked. Upgraded guest 
additions in Linux template. Everyone really loved the speed improvements
and responsiveness, until users reported that no one could mount a usb key any 
more. Yes, I have updated the settings for the pool and usb redirections is 
selected. Thinking that things might have changed a bit in version 4.* of 
VirtualBox I created a new VM (32 bits) using latest Ubuntu. The result is 
that all the keys that I tried (about 8 different manufactures)  are mounting
every time in Virtual Machine run on a Stand alone VirtualBox. The moment I 
import the VM in Solaris box it all stops. On all the keys I am getting IO 
errors.
 I'd been hacking at this for a wile trying make it work, but unfortunately I 
am running out of time. Next week the new MS'c and Ph'd students are about to 
start and one of the key features that worked for 2 years is not working.

I have gathered a bit of information and log snippets. There was a problem 
with utdevmgrd which could not bind to port 7011. I had to change to localhost 
7010 in auth.permit. The new desktop provider wizard ( all components 
including storage are running on one box) when encryption is ticked off
wanted to use 7011 as well. Not sure how it all fits together.
Here are the bits divided in sections for Linux and Solaris parts 
respectively.  I have also tried 5 different SunRay units with the same result.

Would be most grateful for any suggestion and hint.


################## Linux Ubuntu entries (karmik Koala (LTS) and Nutty 
#############

  10.592523] [drm] Initialized drm 1.1.0 20060810
[   10.594215] pci 0000:00:02.0: PCI INT A -> Link[LNKB] -> GSI 11 (level, 
low) -> IRQ 11
[   10.594231] pci 0000:00:02.0: setting latency timer to 64
[   10.595577] [drm] Initialized vboxvideo 1.0.0 20090303 for 0000:00:02.0 on 
minor 0
[   14.296779] RPC: Registered udp transport module.
[   14.296782] RPC: Registered tcp transport module.
[   14.296783] RPC: Registered tcp NFSv4.1 backchannel transport module.
[   14.370992] svc: failed to register lockdv1 RPC service (errno 97).
[   15.514081] Initializing USB Mass Storage driver...
[   15.514121] usbcore: registered new interface driver usb-storage
[   15.515080] USB Mass Storage support registered.
#################################################[ 1703.500226] usb 1-1: new 
full speed USB device using ohci_hcd and address 2
[ 1713.790940] usb 1-1: string descriptor 0 read error: -110
[ 1713.791128] usb 1-1: configuration #1 chosen from 1 choice
[ 1718.801172] usb 1-1: can't set config #1, error -110
##################################################

Solaris x86_64


bash-3.00# utdevadm 

Sun Ray Device Service         Status      
------------------------------ ------------
internal_serial                disabled    
internal_smartcard_reader      enabled     
usb                            enabled     

inserting key into Linux desktop
################################

/tmp/SUNWut/units/IEEE802.0021283a0127/devices/usb@1

##############################################


 modinfo | grep vbox
153 ffffffffec3e5750    b28 233   1  vboxnet (VirtualBox NetAdp 4.0.10r72436)
155 ffffffffec453000  2ca98 232   1  vboxdrv (VirtualBox HostDrv 4.0.10r72436)
221 ffffffffecc82000   7250 234   1  vboxflt (VirtualBox NetDrv 4.0.10r72436)
221 ffffffffecc82000   7250   -   1  vboxflt (VirtualBox NetMod 4.0.10r72436)



###############################################
utdesktop -p 0021283a0127
Current Properties:
  Desktop ID            = 0021283a0127
  Model                 = SunRayP8
  Firmware Revision     = 4.3_146928-01_2011.06.03.14.41
  Multihead Group       = 
  Location              = 
  Token Reader          = no
  Other Info            = 

  Current Status        = Connected
  Current Token         = Payflex.5014b84f00130100 (bruloay)
################################################


tail -f uttscpd.log
2011.09.22 13:32:15.546258 BST unit_event[term=IEEE802.0021283a0127]
[devid=16]: unitid=1.0.0
2011.09.22 13:32:15.546406 BST dev_open[term=IEEE802.0021283a0127][devid=16]
2011.09.22 13:32:15.546492 BST dev_open[term=IEEE802.0021283a0127][devid=16]: 
we already own the device
2011.09.22 13:32:15.546518 BST dev_reset[term=IEEE802.0021283a0127][devid=16]
2011.09.22 13:32:15.848313 BST detach event[term=IEEE802.0021283a0127]
[devid=16]
2011.09.22 13:32:17.194408 BST device event[term=IEEE802.0021283a0127]
[devid=16]
2011.09.22 13:32:17.194493 BST send_response[devid=16]: rtype=2, status=0
2011.09.22 13:32:17.206151 BST unit_event[term=IEEE802.0021283a0127]
[devid=16]: unitid=1.0.0
2011.09.22 13:32:17.206270 BST dev_open[term=IEEE802.0021283a0127][devid=16]
2011.09.22 13:32:17.206313 BST dev_open[term=IEEE802.0021283a0127][devid=16]: 
we already own the device

######  reinserting the key ##############################

2011.09.22 13:35:29.119878 BST read_data: EOF
2011.09.22 13:35:29.120106 BST detach event[term=IEEE802.0021283a0127]
[devid=16]
2011.09.22 13:35:33.057613 BST queue_request[devid=16]: Failed to find device.
2011.09.22 13:35:33.057650 BST ut_usb_send_vbox_cmd[devid=16]: queue request 
failed

####  utstoraged.log #####################################
-bash-3.00# tail -f utstoraged.log
2011.09.22 11:09:56.492044 BST servicing 
/tmp/SUNWut/units/IEEE802.0021283a0127/devices/usb@1/SMI_CorporationUSB_DISK, 
lun=0, ctlmin=1, uid=150040, xid=25
2011.09.22 11:33:24.294472 BST service END lun=0, ctlmin=1, uid=150040, xid=25
########## utmountd.log###############################
2011.09.22 13:31:56.209980 BST [device uid=150040 xid=25 ctlmin=1 
devroot=/tmp/SUNWut/units/IEEE802.0021283a0127 media=disk]
2011.09.22 13:31:56.814317 BST [detach uid=150040 xid=25 ctlmin=1 
devroot=/tmp/SUNWut/units/IEEE802.0021283a0127 media=disk]
mount: I/O error
########################################################

different USB key:

utsoraged.log
2011.09.22 13:40:00.455267 BST servicing 
/tmp/SUNWut/units/IEEE802.0021283a0127/devices/usb@1/USB2.0+AAAAAA-
USB2.0+AAAAAAAAAAAAAAAAAAAAAAAAAAA-, lun=0, ctlmin=1, uid=150040, xid=25
2011.09.22 13:40:01.502866 BST service END lun=0, ctlmin=1, uid=150040, xid=25


############### uttscpd.log ####################

2011.09.22 13:42:17.713384 BST ut_rdd_init: Initialize.
2011.09.22 13:42:17.713697 BST dev_open[term=IEEE802.0021283a0127][devid=19]: 
allocating device for user 150040
2011.09.22 13:42:17.713724 BST rdd_listen: Waiting for rdd connection from 
134.151.159.1 on port 41699
2011.09.22 13:42:17.713759 BST dev_open[term=IEEE802.0021283a0127][devid=19]: 
Device allocate requested
2011.09.22 13:42:17.916327 BST unit_event[term=IEEE802.0021283a0127]
[devid=19]: unitid=1.0.0
2011.09.22 13:42:17.916525 BST rdd_listen: rdd connection established from 
134.151.159.1 on port 41699
2011.09.22 13:42:17.916648 BST rdd_event[term=IEEE802.0021283a0127]: rdd 
connection established
2011.09.22 13:42:17.916871 BST device event[term=IEEE802.0021283a0127]
[devid=19]
2011.09.22 13:42:17.916944 BST dev_open[term=IEEE802.0021283a0127][devid=19]: 
allocate request succeeded2011.09.22 13:42:17.917031 BST 
send_response[devid=19]: rtype=0, status=0

##### and then more looping ###################

unit_event[term=IEEE802.0021283a0127][devid=19]: unitid=1.0.0
2011.09.22 13:42:36.659287 BST dev_open[term=IEEE802.0021283a0127][devid=19]
2011.09.22 13:42:36.659353 BST dev_open[term=IEEE802.0021283a0127][devid=19]: 
we already own the device
2011.09.22 13:42:36.659371 BST dev_reset[term=IEEE802.0021283a0127][devid=19]
2011.09.22 13:42:36.961279 BST detach event[term=IEEE802.0021283a0127]
[devid=19]
2011.09.22 13:42:38.307294 BST device event[term=IEEE802.0021283a0127]
[devid=19]
2011.09.22 13:42:38.307402 BST send_response[devid=19]: rtype=2, status=0
2011.09.22 13:42:38.319029 BST unit_event[term=IEEE802.0021283a0127]
[devid=19]: unitid=1.0.0
2011.09.22 13:42:38.319179 BST dev_open[term=IEEE802.0021283a0127][devid=19]
2011.09.22 13:42:38.319273 BST dev_open[term=IEEE802.0021283a0127][devid=19]: 
we already own the device

##### utstoraged.log #######################

/tmp/SUNWut/units/IEEE802.0021283a0127/devices/usb@1/USB2.0+AAAAAA-
USB2.0+AAAAAAAAAAAAAAAAAAAAAAAAAAA-, lun=0, ctlmin=1, uid=150040, xid=25
2011.09.22 13:40:01.502866 BST service END lun=0, ctlmin=1, uid=150040, xid=25

###### utmountd.log #####################
2011.09.22 13:40:00.455401 BST [device uid=150040 xid=25 ctlmin=1 
devroot=/tmp/SUNWut/units/IEEE802.0021283a0127 media=disk]
2011.09.22 13:40:01.502984 BST [detach uid=150040 xid=25 ctlmin=1 
devroot=/tmp/SUNWut/units/IEEE802.0021283a0127 media=disk]
mount: I/O error
#####
tail -f auth_log
utdmevent: could not connect todevice manager
utdmevent: could not connect todevice manager
utdmevent: could not connect todevice manager
################
/var/opt/SUNWut/log
################

cacaoadm get-param java-home
java-home=/usr/jdk/jdk1.5.0_22

( I have switched to 1.6 on advice of Oracle support with regard to re-
registering olaris box for updates. Had to switch back cacao is also on the 
latest patch)

Snippets from messages since the upgrade (16th of August)

cacao:vda[14971]: [ID 702911 daemon.warning] 
com.sun.vda.service.client.ClientRequestWorker.run : Failed executing vda-
client request: (): Unsupported command: [ExitCode=3]
Sep 20 10:46:11 nn-sgd utauthd: [ID 613541 user.info] Worker2 NOTICE: 
readMessage::socket looping limit exceeded.Close it.
Sep 20 10:46:11 nn-sgd utauthd: [ID 474209 user.info] Worker2 NOTICE: 
DISCONNECT IEEE802.00212812cfc4, pseudo.00212812cfc4 destroy
Sep 20 10:46:11 nn-sgd utauthd: [ID 147217 user.info] Worker2 UNEXPECTED: 
during send to: java.net.SocketOutputStream@25ef6c 
error=java.net.SocketException: Broken pipe

nn-gibbs.aston.ac.uk  0x0.0x2c82221 0:21:28:12:cf:c6 Network: TCBDaemon: 
packet receive error
Sep 18 23:33:41 nn-archimedes.aston.ac.uk  0x0.0x2c872d2 0:14:4f:e7:d4:94 
Network: TCBDaemon: packet receive error
Sep 18 23:33:41 nn-dirac.aston.ac.uk  0x0.0x38bb1c9 0:21:28:3a:0:98 Network: 
TCBDaemon: packet receive error
Sep 18 23:33:42 nn-archimedes.aston.ac.uk  0x0.0x2c87315 0:14:4f:e7:d4:94 
Application: authentication connection read failed. Restarting.
Sep 18 23:33:42 nn-dirac.aston.ac.uk  0x0.0x38bb22d 0:21:28:3a:0:98 Network: 
TCBDaemon: packet receive error
Sep 18 23:33:42 nn-sgd utauthd: [ID 777381 user.info] Worker7 NOTICE: 
readMessage::socket looping limit exceeded.Close it.
Sep 18 23:33:42 nn-sgd utauthd: [ID 444217 user.info] Worker7 NOTICE: 
DISCONNECT IEEE802.00144fe7d494, pseudo.00144fe7d494 destroy
Sep 18 23:33:42 nn-sgd utauthd: [ID 826163 user.info] Worker7 UNEXPECTED: 
during send to: java.net.SocketOutputStream@16b517e 
error=java.net.SocketException: Broken pipe

nn-sgd cacao:vda[14971]: [ID 702911 daemon.warning] 
com.sun.vda.vbox.ws.impl.VirtualBox32Impl.handleGetVersionException : Failed 
to connect to VirtualBox host http://nn-sgd.aston.ac.uk:18083

 kiosk:vda[16794]: [ID 702911 user.notice] The connection has been prematurely 
disconnected.
Sep 16 12:12:48 nn-sgd Sun Ray Connector proxy:[16811]: [ID 855542 user.error] 
Child closed socket prematurely, session shutdown
Sep 16 12:12:48 nn-sgd kiosk:vda[16817]: [ID 702911 user.error] 
/opt/SUNWuttsc/bin/uttsc exited with error code 17 - exiting


kiosk:vda[18601]: [ID 702911 user.notice] Disconnected by Terminal Server.
Sep 16 13:51:30 nn-sgd kiosk:vda[20322]: [ID 702911 user.error] 
/opt/SUNWuttsc/bin/uttsc exited with error code 1 - exiting
Sep 16 13:53:04 nn-sgd kiosk:vda[20689]: [ID 702911 user.notice] Disconnected 
by Terminal Server.
Sep 16 13:53:04 nn-sgd kiosk:vda[20847]: [ID 702911 user.error] 
/opt/SUNWuttsc/bin/uttsc exited with error code 1 - exiting
Sep 16 13:53:18 nn-sgd cacao:vda[14971]: [ID 702911 daemon.info] 
com.sun.vda.service.core.jobs.Job.run : Starting Job[424]: START_VB_DESKTOP 
for [cs_NNrsrch]
Sep 16 13:55:05 nn-sgd kiosk:vda[21106]: [ID 702911 user.notice] Disconnected 
by Terminal Server.
Sep 16 13:55:05 nn-sgd kiosk:vda[21585]: [ID 702911 user.error] 
/opt/SUNWuttsc/bin/uttsc exited with error code 1 - exiting
Sep 16 14:02:10 nn-sgd kiosk:vda[22332]: [ID 702911 user.notice] Disconnected 
by Terminal Server.
Sep 16 14:02:10 nn-sgd kiosk:vda[23753]: [ID 702911 user.error] 
/opt/SUNWuttsc/bin/uttsc exited with error code 1 - exiting
Sep 16 14:04:52 nn-sgd kiosk:vda[23889]: [ID 702911 user.notice] Disconnected 
by Terminal Server.
Sep 16 14:04:52 nn-sgd kiosk:vda[24736]: [ID 702911 user.error] 
/opt/SUNWuttsc/bin/uttsc exited w


messages.0:Sep 21 16:37:17 nn-sgd utdevmgrd[10726]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:22 nn-sgd utdevmgrd[10836]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:27 nn-sgd utdevmgrd[10838]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:32 nn-sgd utdevmgrd[10840]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:37 nn-sgd utdevmgrd[10842]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:42 nn-sgd utdevmgrd[10844]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:47 nn-sgd utdevmgrd[10846]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:52 nn-sgd utdevmgrd[10865]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:37:52 [134.151.159.8.2.2]  0x0.0x58a 0:21:28:3a:1:27 USB: 
rdd: unable to contact device manager on 134.151.159.1:7011 retrying
messages.0:Sep 21 16:37:52 [134.151.159.7.2.2]  0x0.0x58b 0:21:28:3a:0:7b USB: 
rdd: unable to contact device manager on 134.151.159.1:7011 retrying
messages.0:Sep 21 16:37:52 [134.151.159.10.2.2]  0x0.0x58b 0:21:28:3a:25:79 
USB: rdd: unable to contact device manager on 134.151.159.1:7011 retrying
messages.0:Sep 21 16:37:52 [134.151.159.15.2.2]  0x0.0x58b 0:21:28:12:dd:b2 
USB: rdd: unable to contact device manager on 134.151.159.1:7011 retrying
messages.0:Sep 21 16:37:52 [134.151.159.9.2.2]  0x0.0x58b 0:21:28:39:f8:aa 
USB: rdd: unable to contact device manager on 134.151.159.1:7011 retrying
messages.0:Sep 21 16:37:57 nn-sgd utdevmgrd[11553]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:38:02 nn-sgd utdevmgrd[11590]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:38:06 [134.151.159.4.2.2]  0x0.0xb04 0:21:28:3a:1:2d USB: 
rdd: unable to contact device manager on 134.151.159.1:7011 retrying
messages.0:Sep 21 16:38:07 nn-sgd utdevmgrd[11595]: [ID 270105 daemon.error] 
Could not listen on port 7011
messages.0:Sep 21 16:38:12 nn-sgd utauthd: [ID 826456 user.info] 
deviceManager1 NOTICE: DeviceManager.getDeviceManager: Initiate callback to 
utdevMgrd at localhost:7011
messages.0:Sep 21 19:28:31 nn-sgd utauthd: [ID 570116 user.info] Worker4 
NOTICE: DISCONNECT IEEE802.00212812ffb7, user.1315777014-1032 token removed: 
user.1315777014-1032
messages.3:Sep 18 23:33:42 nn-archimedes.aston.ac.uk  0x0.0x2c87362 
0:14:4f:e7:d4:94 USB: rdd: unable to contact device manager on 
134.151.159.1:7011 retrying
messages.3:Sep 18 23:33:45 nn-gibbs.aston.ac.uk  0x0.0x2c823ab 
0:21:28:12:cf:c6 USB: rdd: unable to contact device manager on 
134.151.159.1:7011 re


ps -ef | grep utdev
    root 10354     1   0 16:37:12 ?           0:00 /opt/SUNWut/lib/utdevmgrd -
r -c /etc/opt/SUNWut/auth.permit
    root 11731 10354   0 16:38:12 ?           0:05 /opt/SUNWut/lib/utdevmgrd -
r -c /etc/opt/SUNWut/auth.permit
#################

Checking all the relevant ports

 lsof -i TCP:7007
COMMAND     PID   USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
utaction    170   root    4u  IPv6 0xfffffea1e53ab700    0t110  TCP nn-
sgd.aston.ac.uk:61387->nn-sgd.aston.ac.uk:utsessiond (ESTABLISHED)
utaudio     231 utku45    0u  IPv6 0xfffffea1e5796000    0t110  TCP nn-
sgd.aston.ac.uk:61388->nn-sgd.aston.ac.uk:utsessiond (ESTABLISHED)

lsof -i TCP:7009
java    10358 root   37u  IPv4 0xfffffea1dd1eb740 0t138520  TCP nn-
sgd.aston.ac.uk:utauthd->134.151.159.36:51919 (ESTABLISHED)
java    10358 root   57u  IPv4 0xfffffea1ddd86940      0t0  TCP *:utauthd 
(LISTEN)


lsof -i TCP:7010
COMMAND     PID USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
java      10358 root   14u  IPv4 0xfffffea1e48e4d80 0t256083  TCP 
localhost:utauthd-cb->localhost:40698 (ESTABLISHED)
java      10358 root   26u  IPv4 0xfffffea1dd1f1000     0t42  TCP 
localhost:utauthd-cb->localhost:40742 (ESTABLISHED)
java      10358 root   51u  IPv4 0xfffffea1dd1e1880      0t0  TCP *:utauthd-cb 
(LISTEN)
utsession 10361 root    5u  IPv6 0xfffffea1e48e5440 0t513480  TCP 
localhost:40698->localhost:utauthd-cb (ESTABLISHED)
utdevmgrd 11731 root   17u  IPv6 0xffffffff80244040 0t140359  TCP 
localhost:40742-
>localhost:utauthd-cb (ESTABLISHED)

 lsof -i TCP:7011
COMMAND     PID USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
utdevmgrd 11731 root    5u  IPv6 0xfffffea1dd1fbb40      0t0  TCP *:utdevmgrd 
(LISTEN)
utdevmgrd 11731 root   20u  IPv6 0xfffffea1ddb82dc0 0t191793  TCP nn-
sgd.aston.ac.uk:utdevmgrd->134.151.159.8:45869 (ESTABLISHED)
utdevmgrd 11731 root   21u  IPv6 0xfffffea1ddb7fe00  0t80928  TCP nn-
sgd.aston.ac.uk:utdevmgrd->134.151.159.7:53354 (ESTABLISHED)

uttscpd   581 utku45    4u  IPv6 0xfffffea1e5885480     0t189  TCP nn-
sgd.aston.ac.uk:61577->nn-sgd.aston.ac.uk:utdsd (ESTABLISHED)
utdsd    1037   root    5u  IPv6 0xfffffea1d5bfb000       0t0  TCP *:utdsd 
(LISTEN)
utdsd    1037   root   13u  IPv6 0xfffffea1dd4501c0 0t2688063  TCP nn-
sgd.aston.ac.uk:utdsd->nn-sgd.aston.ac.uk:34159 (ESTABLISHED)
utdsd    1037   root   22u  IPv6 0xfffffea1e588a0c0     0t303  TCP nn-
sgd.aston.ac.uk:utdsd->nn-sgd.aston.ac.uk:38540 (ESTABLISHED)
utdsd    1037   root   23u  IPv6 0xfffffea1e5952440     

I understand that there is  lot of info here. I just hope that may be someone 
already came across this issues. Goggling for it did not work for me.

Thank you


Best wishes

Alex 
=======================================
Alex Brulo
Senior Server Engineer (HPC)
Information Systems Aston (ISA)
Aston University, Aston Triangle,
Birmingham, B4 7ET 
Tel: 0121 204 3673
ISA "Aiming for Excellence in ICT Services" 
=======================================
Please consider the environment before printing this e-mail
=======================================

_______________________________________________
SunRay-Users mailing list
[email protected]
http://www.filibeto.org/mailman/listinfo/sunray-users

Reply via email to