Hi, I have managed to test the version : smartos-20140530T010428Z
The rmformat -l issue is confirmed gone. So it may be fixed in between somewhere :) Thanks again. On Sat, May 31, 2014 at 3:47 PM, Yu Li <[email protected]> wrote: > Thx for your local try :) > > However, I still have this issue. So I have manage to provide more info > > First of all, I got below on a VirtualBox (but this happens in my real > hardware, which is a dell desktop) > > [root@08-00-27-a9-9a-26 ~]# uname -v > joyent_20140501T225642Z > [root@08-00-27-a9-9a-26 ~]# time rmformat -l > Looking for devices... > 1. Logical Node: /dev/rdsk/c0t1d0p0 > Physical Node: /pci@0,0/pci8086,2829@d/cdrom@1,0 > Connected Device: VBOX CD-ROM 1.0 > Device Type: DVD Reader > Bus: <Unknown> > Size: 679.7 MB > Label: <None> > Access permissions: <Unknown> > > real 1m0.143s > user 0m0.006s > sys 0m0.024s > > You can see that 1m real time. Actually, the results before the Label line > populates out first, then after 1m, Label and access lines appear. > > I have done some dtrace stuff (but I am not a dtrace expert :)), the > script is > > [root@08-00-27-a9-9a-26 /opt]# cat r.d > syscall:::entry > /pid == $target/ > { > self->t = timestamp; > } > > syscall:::return > /self->t/ > { > @systime[execname, probefunc] = sum(timestamp - self->t); > self->t = 0; > } > > dtrace:::END > { > printa("%15s %15s %@15u\n", @systime); > } > > And the results are: > > [root@08-00-27-a9-9a-26 /opt]# dtrace -s r.d -c "rmformat -l" > dtrace: script 'r.d' matched 465 probes > Looking for devices... > 1. Logical Node: /dev/rdsk/c0t1d0p0 > Physical Node: /pci@0,0/pci8086,2829@d/cdrom@1,0 > Connected Device: VBOX CD-ROM 1.0 > Device Type: DVD Reader > Bus: <Unknown> > Size: 679.7 MB > Label: <None> > Access permissions: <Unknown> > dtrace: pid 62472 has exited > CPU ID FUNCTION:NAME > 0 2 :END rmformat > labelsys 1953 > rmformat setcontext 2342 > rmformat sigpending 2610 > rmformat privsys 2736 > rmformat getrlimit 3048 > rmformat zone 3458 > rmformat getuid 3852 > rmformat gtime 3905 > rmformat uname 4287 > rmformat getpid 4856 > rmformat readlink 4922 > rmformat sysconfig 6722 > rmformat sysi86 7311 > rmformat lstat64 7379 > rmformat llseek 10993 > rmformat fcntl 13843 > rmformat chdir 19534 > rmformat fstat64 24672 > rmformat schedctl 25876 > rmformat getcwd 27494 > rmformat brk 30545 > rmformat openat 42381 > rmformat memcntl 48134 > rmformat mmap 52093 > rmformat resolvepath 65762 > rmformat getdents64 67369 > rmformat lwp_cond_broadcast 91472 > rmformat munmap 92840 > rmformat fstat 114936 > rmformat read 134970 > rmformat open64 157031 > rmformat putmsg 191423 > rmformat write 193405 > rmformat stat64 226050 > rmformat mmapobj 326062 > rmformat close 384007 > rmformat open 513954 > rmformat lwp_sigmask 551511 > rmformat getmsg 12365946 > rmformat ioctl 53940501 > rmformat pollsys 60016272302 > > So the obvious thing is that pollsys use too much time. And I believe that > it is just retry and sleep for sth. So this may be more complex than I > think (or even it is not in the rmformat side, it should only do simple > things.) > > To reproduce the situation, I believe you can just use > smartos_20140501T225642Z.iso to boot the system in a VirtualBox VM. > > I will also try to use your smartos version for a try, may be this issue > is gone while nobody notice it (except me :)). > > On Sat, May 31, 2014 at 2:23 AM, Keith Wesolowski < > [email protected]> wrote: > >> On Fri, May 30, 2014 at 04:29:52PM +0800, Yu Li wrote: >> >> > Sorry for such a delay. Anyway I have managed to populate the truss log >> > >> > the interesting part is as follows >> > >> > getpid() = 10843 [10842] >> > fstat(7, 0x08046868) = 0 >> > ioctl(7, I_STR, 0x080469B0) = 0 >> > time() = 1401438253 >> > fstat(7, 0x080468E8) = 0 >> > putmsg(7, 0x08046A04, 0x08046AD4, 0) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) (sleeping...) >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) = 0 >> > fstat(7, 0x080468E8) = 0 >> > putmsg(7, 0x08046A04, 0x08046AD4, 0) = 0 >> > >> > pollsys(0x080A4A24, 1, 0x08046A38, 0x00000000) (sleeping...) >> > >> > (...and this continues to previous one) >> > >> > I suspect that this is just sth wrong in reading my usb's bus info, and >> > have to retry to many times? >> >> What is being polled here? You can either use DTrace to look at this in >> more detail or use the debugger to see what's in the poll structure. >> Then use pfiles so see what that refers to. >> >> This is probably going to be a lot easier with DTrace; I'd start with >> something simple like looking at the kernel stacks at the time we go off >> CPU, which will tell us what the poll is actually waiting on (which is >> what we want to know anyway). >> >> Since it would be easier to debug this myself, I tried it here locally, >> but could not reproduce the behaviour you are seeing: >> >> [root@headnode (sf-3) ~]# uname -v >> joyent_20140519T165600Z >> [root@headnode (sf-3) ~]# time rmformat -l >> Looking for devices... >> 1. Logical Node: /dev/rdsk/c16t0d0p0 >> Physical Node: /pci@0,0/pci15d9,702@1d/hub@1/storage@7/disk@0,0 >> Connected Device: Kingston DT Rubber 3.0 1.01 >> Device Type: Removable >> Bus: USB >> Size: 15.0 GB >> Label: <Unknown> >> Access permissions: <Unknown> >> >> real 0m0.029s >> user 0m0.004s >> sys 0m0.013s >> >> That means this is most likely going to be something specific to your >> hardware, or perhaps to the data on your USB key or some other device. >> Maybe OS-1952 or something like it is involved >> (http://smartos.org/bugview/OS-1952). >> > > ------------------------------------------- smartos-discuss Archives: https://www.listbox.com/member/archive/184463/=now RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00 Modify Your Subscription: https://www.listbox.com/member/?member_id=25769125&id_secret=25769125-7688e9fb Powered by Listbox: http://www.listbox.com
