Page 1 of 1

Bookpedia asynchronous startup

Posted: Wed Dec 25, 2013 1:37 pm
by otab
I have a modestly-sized set of books catalogued with Bookpedia (755 to be exact). The time between launching the app and the app being usable is somewhere north of 45 seconds. During that time, the app is completely non-responsive, and the beach ball is spinning. Contrast this with, oh, say Apple Aperture (where I have somewhere north of 125,000 images stored), which launches and is completely usable on my rMBP in under 5 seconds.

It'd sure be nice if Bookpedia's launch were more like Aperture's, and I didn't have to twiddle my thumbs for a full minute or so before adding a new book...

Re: Bookpedia asynchronous startup

Posted: Sat Dec 28, 2013 7:53 am
by Conor
Thank you for the feedback. Something more interesting must be going on. Bookpedia should be fairly quick to launch. For example on my MacBook Pro 2.53 GHz Intel i5 with 1,674 books it takes 1.56 seconds to go from launching to waiting for user input.

The only thing I could think of is that you are you in a smart collection folder that is really complex and Bookpedia is trying to update that information?

Otherwise do please send me a sample with Activity Monitor of these time while Bookpedia is launching and might tell us more about where it's spending it's time thinking about.

Also if you don't mind do send me your data file and I can take a look at that myself. You will find the database in your data folder located in your home folder at ~/Library/Application Support/Bookpedia/Database.bookpd. Under Lion you must use the Finder menu "Go -> Go To..." command and enter "~/Library/Application Support/Bookpedia" to open the folder. Once there select the Database.bookpd and use the "Compress" command under the main "File" menu. This will create a .zip version that you can then attach to an email message.

Re: Bookpedia asynchronous startup

Posted: Sun Jan 05, 2014 3:10 pm
by otab
I'll be happy to send you my db file and an Activity Monitor sample, but to what email address?

I'm not in a smart collection, just in "Library". As a matter of fact, I have *no* smart collections.

I'd thought it might be related to the Doghouse moderator collections, but the startup time was no faster when I turned those off.

Looking at the activity monitor sample, I see a lot about Bluetooth. Possibly it's trying to talk to my Bluetooth barcode reader (which I keep turned off most of the time)?

-- Aaron

Here's the text of the sample (minus the binary images portion, which drives the message size past the board's message size limit):

Code: Select all

Sampling process 38472 for 3 seconds with 1 millisecond of run time between samples
Sampling completed, processing symbols...
Analysis of sampling Bookpedia (pid 38472) every 1 millisecond
Process:         Bookpedia [38472]
Path:            /Applications/Bookpedia.app/Contents/MacOS/Bookpedia
Load Address:    0x1000
Identifier:      com.bruji.bookpedia
Version:         5.2 (5.2)
Code Type:       X86
Parent Process:  launchd [156]

Date/Time:       2014-01-05 14:06:13.851 -0600
OS Version:      Mac OS X 10.9.1 (13B42)
Report Version:  7

Call graph:
    2679 Thread_16788405   DispatchQueue_1: com.apple.main-thread  (serial)
    + 2679 ???  (in Bookpedia)  load address 0x1000 + 0x15f9  [0x25f9]
    +   2679 NSApplicationMain  (in AppKit) + 1165  [0x96e571f8]
    +     2679 -[NSApplication run]  (in AppKit) + 727  [0x96e6e35c]
    +       2679 -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]  (in AppKit) + 119  [0x96e7bad0]
    +         2679 _DPSNextEvent  (in AppKit) + 1089  [0x96e7c3a8]
    +           2679 AEProcessAppleEvent  (in HIToolbox) + 55  [0x980657c1]
    +             2679 aeProcessAppleEvent  (in AE) + 318  [0x9b5a2dce]
    +               2679 dispatchEventAndSendReply(AEDesc const*, AEDesc*)  (in AE) + 44  [0x9b5a2ed6]
    +                 2679 aeDispatchAppleEvent(AEDesc const*, AEDesc*, unsigned long, unsigned char*)  (in AE) + 387  [0x9b5d3b15]
    +                   2679 _NSAppleEventManagerGenericHandler  (in Foundation) + 218  [0x964a0d3b]
    +                     2679 -[NSAppleEventManager dispatchRawAppleEvent:withRawReply:handlerRefCon:]  (in Foundation) + 430  [0x964a0f31]
    +                       2679 __76-[NSAppleEventManager setEventHandler:andSelector:forEventClass:andEventID:]_block_invoke  (in Foundation) + 121  [0x964a13fa]
    +                         2679 -[NSObject performSelector:withObject:withObject:]  (in libobjc.A.dylib) + 77  [0x9951e304]
    +                           2679 -[NSApplication(NSAppleEventHandling) _handleCoreEvent:withReplyEvent:]  (in AppKit) + 277  [0x96e80691]
    +                             2679 -[NSApplication(NSAppleEventHandling) _handleAEOpenEvent:]  (in AppKit) + 840  [0x96e80da4]
    +                               2679 -[NSApplication _sendFinishLaunchingNotification]  (in AppKit) + 239  [0x96e84475]
    +                                 2679 -[NSApplication _postDidFinishNotification]  (in AppKit) + 367  [0x96e847d5]
    +                                   2679 -[NSNotificationCenter postNotificationName:object:userInfo:]  (in Foundation) + 92  [0x96480ebf]
    +                                     2679 _CFXNotificationPost  (in CoreFoundation) + 3435  [0x967f63fb]
    +                                       2679 __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__  (in CoreFoundation) + 20  [0x969147e4]
    +                                         2679 __57-[NSNotificationCenter addObserver:selector:name:object:]_block_invoke  (in Foundation) + 49  [0x96492692]
    +                                           2679 ???  (in Bookpedia)  load address 0x1000 + 0x8931  [0x9931]
    +                                             2679 -[MyControllerShared(ApplicationNotifications) applicationDidFinishLaunching:]  (in Pediabase) + 1932  [0xc0f3707a]
    +                                               2679 -[MyBluetoothScanner conectToPairedDevices]  (in Pediabase) + 239  [0xc101dd79]
    +                                                 2679 -[IOBluetoothDevice openConnection]  (in IOBluetooth) + 41  [0x90376c29]
    +                                                   2679 -[IOBluetoothDevice openConnection:]  (in IOBluetooth) + 56  [0x9037700a]
    +                                                     2679 -[IOBluetoothDevice openConnection:withPageTimeout:authenticationRequired:]  (in IOBluetooth) + 64  [0x9036c5bf]
    +                                                       2679 -[IOBluetoothDevice openConnection:withPageTimeout:authenticationRequired:allowRoleSwitch:]  (in IOBluetooth) + 1871  [0x9036cd17]
    +                                                         2679 -[IOBluetoothHostController BluetoothHCICreateConnection:inPacketType:inPageScanRepetitionMode:inReserved:inClockOffset:inAllowRoleSwitch:outConnectionCompleteResults:]  (in IOBluetooth) + 620  [0x903baddb]
    +                                                           2679 BluetoothHCIDispatchUserClientRoutine  (in IOBluetooth) + 90  [0x90362ddd]
    +                                                             2679 IOConnectCallStructMethod  (in IOKit) + 84  [0x95fce1ef]
    +                                                               2679 IOConnectCallMethod  (in IOKit) + 546  [0x95fcdf33]
    +                                                                 2679 io_connect_method  (in IOKit) + 424  [0x96032a4c]
    +                                                                   2679 mach_msg  (in libsystem_kernel.dylib) + 68  [0x9329816c]
    +                                                                     2679 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x93298f7a]
    2679 Thread_16788435   DispatchQueue_2: com.apple.libdispatch-manager  (serial)
    + 2679 _dispatch_mgr_thread  (in libdispatch.dylib) + 52  [0x91e0d556]
    +   2679 _dispatch_mgr_invoke  (in libdispatch.dylib) + 238  [0x91e0d8bd]
    +     2679 kevent64  (in libsystem_kernel.dylib) + 10  [0x9329e992]
    2679 Thread_16788437
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788440
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788509
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788510
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788511
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788512
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788525
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788526
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788527
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788528
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788529
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788530
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788531
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788532
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788533
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788534
    + 2679 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
    +   2679 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
    +     2679 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]
    2679 Thread_16788535: CVDisplayLink
    + 2679 thread_start  (in libsystem_pthread.dylib) + 34  [0x95237cf2]
    +   2679 _pthread_start  (in libsystem_pthread.dylib) + 130  [0x95232485]
    +     2679 _pthread_body  (in libsystem_pthread.dylib) + 144  [0x952325fb]
    +       2679 startIOThread(void*)  (in CoreVideo) + 159  [0x92b07180]
    +         2679 CVDisplayLink::runIOThread()  (in CoreVideo) + 936  [0x92b07540]
    +           2679 pthread_cond_wait$UNIX2003  (in libsystem_pthread.dylib) + 71  [0x95236bd9]
    +             2679 _pthread_cond_wait  (in libsystem_pthread.dylib) + 728  [0x95234d1d]
    +               2679 __psynch_cvwait  (in libsystem_kernel.dylib) + 10  [0x9329d7ca]
    2596 Thread_16788436
      2596 start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]
        2596 _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
          2596 __workq_kernreturn  (in libsystem_kernel.dylib) + 10  [0x9329e046]

Total number in stack (recursive counted multiple, when >=5):
        17       __workq_kernreturn  (in libsystem_kernel.dylib) + 0  [0x9329e03c]
        17       _pthread_wqthread  (in libsystem_pthread.dylib) + 372  [0x95233dcf]
        17       start_wqthread  (in libsystem_pthread.dylib) + 30  [0x95237cce]

Sort by top of stack, same collapsed (when >= 5):
        __workq_kernreturn  (in libsystem_kernel.dylib)        45460
        __psynch_cvwait  (in libsystem_kernel.dylib)        2679
        kevent64  (in libsystem_kernel.dylib)        2679
        mach_msg_trap  (in libsystem_kernel.dylib)        2679


Re: Bookpedia asynchronous startup

Posted: Sun Jan 05, 2014 3:39 pm
by Conor
Thank you for the details.

Does seem like your computer believes the Bluetooth scanner is connected and is waiting for it to reply with an established connection. Turn off the search for the Bluetooth Scanner under the "Help" menu in Bookpedia. Select the command so there is no check mark next to the Bluetooth command. Then restart Bookpedia and let me know if it fixes the load time. It should not try to connect if the scanner is off, I shall investigate but I think it's a fluke.

Re: Bookpedia asynchronous startup

Posted: Wed Jan 22, 2014 9:32 pm
by otab
Sorry for the long delay in reply: the notification that this post got a new entry ended up in my spam box.

When I launched the app while the scanner was turned off, after the startup delay, the checkmark next to the Bluetooth menu item was unchecked, and I couldn't change it.

I had to turn my bluetooth scanner on, then launch the bookpedia app, then uncheck bluetooth, then turn the scanner back off, quit the app and restart, but that sequence finally resulted in a 1-second launch time. (W00t!)

So, it looks to me like once I've turned bluetooth on once, then bookpedia looks for the scanner again every time it launches, unless I specifically turn the bluetooth check off while the scanner is both turned on and connected?

Maybe it could turn bluetooth back off if it launches and then doesn't find a scanner? Maybe a prompt to ask the user about it?

Re: Bookpedia asynchronous startup

Posted: Thu Jan 23, 2014 4:55 am
by Conor
Glad it was the Bluetooth search that was slowing down the program and you were able to fix it. Normally the Bluetooth auto connect is not an issue as it's performed both threaded and is relatively fast for the most part. Not sure what the settings were on your system that was causing the main thread to also wait for the connection of the bluetooth scanner as well as taking so long to report that it was not available. Your suggestion to stop looking after a few failed attempts is a good one and one that I have added to the next version to test out.