Ok, after disconnecting the USB I got a long (11s) wake-up. Here is the log via showlog. There seems to be a stackdump near the start that causes all sorts of recovery activity, which seems to take up most of the wake-up time?
Code:
121008:134229 powerd[2113]: I def:pbpress:time=1349696549.888:Power button pressed
121008:134229 powerd[2113]: I lipc:evts:name=outOfScreenSaver, origin=com.lab126.powerd, fparam=1:Event sent
121008:134229 powerd[2113]: I def:statech:prev=SCREEN SAVER, next=ACTIVE:State change: SCREEN SAVER -> ACTIVE
121008:134229 powerd[2113]: I def:acc::Turn acc port on
121008:134229 mxc_keyb: I def:unlocked2:status=unlocked:
121008:134229 fiveway: I def:unlock2:status=unlocked:
121008:134229 powerd[2113]: E def:usbfs::Failed to open sys entry for USB FS ONLINE
121008:134229 accelerometer: I def:unlock::status=unlocked
121008:134229 cvm[3214]: I HTTPUtil:clearDNSCache:cache_size=0:clearing DNS cacheMap
121008:134230 lipc-send-event[12789]: I lipc:evts:name=orientationUp, origin=com.lab126.hal:Event sent
121008:134230 system: I dump-stack:dumpstack:cmd:pid=3518:begin native threads ==============================
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: Using host libthread_db library "/lib/libthread_db.so.1".
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134230 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134231 system: I dumpstack:cmd:pid=3518: [Thread debugging using libthread_db enabled]
121008:134231 system: I dumpstack:cmd:pid=3518: [New Thread 1073881104 (LWP 3518)]
121008:134231 system: I dumpstack:cmd:pid=3518: [New Thread 1110348944 (LWP 3522)]
121008:134231 system: I dumpstack:cmd:pid=3518: [New Thread 1101960336 (LWP 3521)]
121008:134231 system: I dumpstack:cmd:pid=3518: [New Thread 1093571728 (LWP 3520)]
121008:134231 system: I dumpstack:cmd:pid=3518: [New Thread 1085183120 (LWP 3519)]
121008:134231 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134231 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134231 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134231 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134231 system: I dumpstack:cmd:pid=3518: (no debugging symbols found)
121008:134231 system: I dumpstack:cmd:pid=3518: 0x4029e260 in pthread_cond_wait@@GLIBC_2.4 () from /lib/libpthread.so.0
121008:134231 system: I dumpstack:cmd:pid=3518: Thread 5 (Thread 1085183120 (LWP 3519)):
121008:134231 system: I dumpstack:cmd:pid=3518: #0 0x4029e260 in pthread_cond_wait@@GLIBC_2.4 () from /lib/libpthread.so.0
121008:134231 system: I dumpstack:cmd:pid=3518: #1 0x4024153c in pthread_cond_wait@@GLIBC_2.4 () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #2 0x0001274c in ?? ()
121008:134231 system: I dumpstack:cmd:pid=3518: Thread 4 (Thread 1093571728 (LWP 3520)):
121008:134231 system: I dumpstack:cmd:pid=3518: #0 0x40206124 in nanosleep () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #1 0x40241aac in __libc_enable_asynccancel () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #2 0x4029102c in __after_morecore_hook () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: Backtrace stopped: frame did not save the PC
121008:134231 system: I dumpstack:cmd:pid=3518: Thread 3 (Thread 1101960336 (LWP 3521)):
121008:134231 system: I dumpstack:cmd:pid=3518: #0 0x40205c04 in waitpid () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #1 0x4017592c in sdump_log_stack_for () from /usr/lib/libstackdump.so.0
121008:134231 system: I dumpstack:cmd:pid=3518: #2 0x40175aac in handle_crash_signal () from /usr/lib/libstackdump.so.0
121008:134231 system: I dumpstack:cmd:pid=3518: #3 <signal handler called>
121008:134231 system: I dumpstack:cmd:pid=3518: #4 0x401e7a00 in strcmp () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #5 0x0000ddb4 in ?? ()
121008:134231 system: I dumpstack:cmd:pid=3518: Thread 2 (Thread 1110348944 (LWP 3522)):
121008:134231 system: I dumpstack:cmd:pid=3518: #0 0x4022fee0 in select () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #1 0x40241aac in __libc_enable_asynccancel () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #2 0x00000000 in ?? ()
121008:134231 system: I dumpstack:cmd:pid=3518: Thread 1 (Thread 1073881104 (LWP 3518)):
121008:134231 system: I dumpstack:cmd:pid=3518: #0 0x4029e260 in pthread_cond_wait@@GLIBC_2.4 () from /lib/libpthread.so.0
121008:134231 system: I dumpstack:cmd:pid=3518: #1 0x4024153c in pthread_cond_wait@@GLIBC_2.4 () from /lib/libc.so.6
121008:134231 system: I dumpstack:cmd:pid=3518: #2 0x0000e988 in ?? ()
121008:134231 system: I dumpstack:cmd:pid=3518: #0 0x4029e260 in pthread_cond_wait@@GLIBC_2.4 () from /lib/libpthread.so.0
121008:134231 system: I dump-stack:dumpstack:cmd:pid=3518:end native threads ================================
121008:134232 system: I tinyrot:def::Rotating file /var/log/messages with max size 256
121008:134232 syslog-ng[807]: SIGHUP received, restarting syslog-ng
121008:134233 arcotg_udc: I def:fs::dr_controller_setup - force_fs = 0
121008:134233 arcotg_udc: I def:uri::resume_irq - resume_irq: usb_slave_regs->usbintr:157
121008:134233 arcotg_udc: I def:udsc::chgdisc_event - USB disconnected
121008:134233 arcotg_udc: I def:usi::suspend_irq - suspend_irq: usb_slave_regs->usbintr:157
121008:134233 arcotg_udc: I def:udsc::chgdisc_event - USB disconnected
121008:134233 syslog-ng[807]: new configuration initialized
121008:134233 lipc-send-event[12924]: I lipc:evts:name=usbPlugOut, origin=com.lab126.hal:Event sent
121008:134233 lipc-send-event[12929]: I lipc:evts:name=usbPlugOut, origin=com.lab126.hal:Event sent
121008:134236 system: I tinyrot:def::Rotating file /var/log/odotlite with max size 2048
121008:134236 system: I tinyrot:def::No file to rotate: /var/log/odotlite
121008:134239 crond[2919]: USER root pid 12965 cmd /usr/sbin/checkpmond
121008:134239 crond[2919]: USER root pid 12966 cmd /usr/sbin/tinyrot
121008:134239 crond[2919]: USER root pid 12967 cmd /usr/sbin/loginfo powerdcheck
121008:134239 cvm[3214]: E lipc:pto::Timed out waiting for sync prop access to complete
121008:134239 cvm[3214]: W lipc:perf:prop=interfaceProperties, source=com.lab126.cmd, ms=10001:lipc property access time in millisecond
121008:134239 cvm[3214]: E ConnectionService:ExceptionCaught::Cannot get interface properties
121008:134239 cvm[3214]: I WirelessImpl:SettingProxyInfo:interface=none:Setting up proxies
121008:134239 cvm[3214]: I URLUtil:UpdateGlobalsTrace::before updating the map
121008:134239 cvm[3214]: I URLUtil:UpdateGlobalsTrace::after updating the map
121008:134239 cvm[3214]: I URLUtil:UpdateGlobalsTrace::before updating the map
121008:134239 cvm[3214]: I URLUtil:UpdateGlobalsTrace::after updating the map
121008:134239 cvm[3214]: I URLUtil:UpdateGlobalsTrace::before updating the map
121008:134239 cvm[3214]: I URLUtil:UpdateGlobalsTrace::after updating the map
121008:134239 cvm[3214]: I SettingsPage:Information::The current view is not the Settings so skip refresh the WiFi widget
121008:134239 cvm[3214]: I LipcService:EventArrived:source=com.lab126.powerd,name=outOfScreenSaver,arg0=1,arg1=<None>:
121008:134239 cvm[3214]: I PowerImpl:Information::handlePowerStateChangeEvent 3 1
121008:134239 cvm[3214]: I lipc:sip:prop=Volume, source=com.lab126.audio, value=7:Set int property
121008:134239 cvm[3214]: I ScreenSaverBooklet:SSB_TRACE_USB_EXPORT:delayUSBExport=false:Password disabled
121008:134239 cvm[3214]: I ScreenSaverBooklet:IncrementSSImage::Incrementing the screen saver image index
121008:134239 cvm[3214]: I ScreenSaverBooklet:SwitchingToLastBooklet:lastBooklet=Home:Switching to last booklet
121008:134239 cvm[3214]: I BookletManager:SwitchingBooklets:from=ScreenSaverBooklet,to=Home:
121008:134239 audioServer[2691]: I volume:set:vol = 7:Setting the volume
121008:134239 audioServer[2691]: E def:mo::Failed to set volume (No master output)
121008:134240 cvm[3214]: W SystemBarImpl:SPIN:spinCount=0:count <=0 when stopSpinner() called
121008:134240 cvm[3214]: I ContentCatalogImpl:ItemIterator:index=0,items=32,volumes=6,time=53:Catalog Iteration done
121008:134240 cvm[3214]: I MainView:Information::The device has WAN module so skip popping up the WiFi dialog.