Ticket #324 (closed Defect: fixed)

Opened 4 months ago

Last modified 4 months ago

Extremely slow file browsing via smb mount

Reported by: ndobson Assigned to:
Priority: normal Milestone:
Component: Other Version: 1.0b7
Keywords: Cc:

Description

Running appletv 3.0.1 with Sapphire 1.0b7.6 Browsing files (smb mounted file system) in a collection is extremely slow and will freeze for up to a minute at a time, also attempting to import data often results in a long pause and subsequent crash. I have no problems sshing to my appletv and listing the files on the smb file system.

I have tried multiple times to change the fast directory switching preference, restart finder, remove the sapphire metadata file, nothing helps.

I have recently switched back to using Sapphire after a long time of only using ATVfiles (with none of these issues). So I am not sure if this is normal behavior in atv 3.0.1

Change History

11/12/09 14:21:36 changed by gbooker

  • milestone set to Awaiting User Feedback.

BugReporting

11/12/09 18:40:51 changed by ndobson

This is the log output i get when entering a directory (which takes forever). I get the same output each time I enter this directory. 

2009-11-12 18:23:56.691 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/katrina-chalmette-2005.avi because a file of class 0 12 != 0
2009-11-12 18:23:56.925 Finder[220] Save successful
2009-11-12 18:23:57.459 Finder[220] Save successful
2009-11-12 18:23:58.948 Finder[220] Save successful
2009-11-12 18:24:01.620 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/2006 White House Correspondents Dinner with Stephen Colbert and Pres. Bush.avi because a file of class 0 12 != 4
2009-11-12 18:24:04.544 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/A Charlie Brown Christmas.avi because a file of class 0 12 != 4
2009-11-12 18:24:04.566 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/A Charlie Brown Thanksgiving.avi because a file of class 0 12 != 4
2009-11-12 18:24:07.547 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/Chris Rock - Bigger and Blacker.avi because a file of class 0 12 != 4
2009-11-12 18:24:07.568 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/Chris Rock - Never Scared.avi because a file of class 0 12 != 4
2009-11-12 18:24:07.589 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/Colbert Saints Rant.wmv because a file of class 0 12 != 4
2009-11-12 18:24:07.609 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/Dave Chappelle - For What It's Worth.avi because a file of class 0 12 != 4
2009-11-12 18:24:07.630 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/Dave Chappelle - Killing Them Softly.avi because a file of class 0 12 != 4
2009-11-12 18:24:07.651 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/Demetri Martin - Person.avi because a file of class 0 12 != 4
2009-11-12 18:24:24.851 Finder[220] Going to import /mnt/Scratch/Users/frontrow/Nick/Video/TV Shows/The Daily Show - Election Night 2004.avi because a file of class 0 12 != 0
2009-11-12 18:24:25.146 Finder[220] Save successful
2009-11-12 18:24:26.535 Finder[220] Save successful
2009-11-12 18:24:26.654 Finder[220] Save successful
2009-11-12 18:24:26.768 Finder[220] Save successful
2009-11-12 18:24:26.885 Finder[220] Save successful
2009-11-12 18:24:26.992 Finder[220] Save successful
2009-11-12 18:24:27.437 Finder[220] Save successful
2009-11-12 18:24:27.556 Finder[220] Save successful
2009-11-12 18:24:27.670 Finder[220] Save successful
2009-11-12 18:24:27.785 Finder[220] Save successful
2009-11-12 18:24:28.411 Finder[220] Save successful
2009-11-12 18:24:28.527 Finder[220] Save successful

11/12/09 20:29:06 changed by gbooker

BugReporting, number 5.

11/13/09 19:37:25 changed by ndobson

first run of sample... 

Analysis of sampling pid 220 every 10.000000 milliseconds
Call graph:
    500 Thread_0113
      500 _pthread_body
        500 CAPThread::Entry(CAPThread*)
          500 HALRunLoop::OwnThread(void*)
            500 CFRunLoopRunInMode
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_020b
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRDisplayManager(DisplayNotificationsPrivate) _windowServerCallbackHandler]
            500 CFRunLoopRun
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_032b
      500 0xe0769
        500 0xe0842
          500 0x5d6b
            500 -[BRAppManager run]
              500 CFRunLoopRunInMode
                500 CFRunLoopRunSpecific
                  500 _handler
                    500 -[BREventManager(EventHandling) _handler]
                      500 0x9c609
                        500 -[BRControl brEventAction:]
                          500 -[BRControllerStack brEventAction:]
                            500 -[BRControl brEventAction:]
                              500 -[SapphireBrowser brEventAction:]
                                500 -[SapphireMediaMenuController brEventAction:]
                                  500 -[BRMediaMenuController brEventAction:]
                                    500 -[BRController brEventAction:]
                                      500 -[BRControl brEventAction:]
                                        500 -[BRListControl brEventAction:]
                                          500 -[BRInvocationSelectionHandler handleSelectionForControl:]
                                            500 -[NSInvocation invoke]
                                              500 objc_msgSendv
                                                500 -[BRMenuController(Deprecated) _itemSelected:]
                                                  500 -[SapphireBrowser itemSelected:]
                                                    500 -[BRControllerStack(TransactionEngine) _processTransactions]
                                                      500 -[BRControllerStack(TransactionEngine) _processPushTransaction:]
                                                        500 -[SapphireBrowser wasPushed]
                                                          500 -[SapphireMediaMenuController wasPushed]
                                                            500 -[SapphireBrowser doInitialPush]
                                                              500 -[SapphireDirectoryMetaData reloadDirectoryContents]
                                                                500 -[SapphireDirectoryMetaData rescanDirWithExistingDirs:files:symDirs:symFiles:]
                                                                  300 -[NSFileManager(SapphireExtensions) acceptFilePath:]
                                                                    299 -[NSFileManager(SapphireExtensions) isDirectory:]
                                                                      299 -[NSFileManager(SapphireExtensions) hasVIDEO_TS:]
                                                                        299 -[NSFileManager fileExistsAtPath:isDirectory:]
                                                                          299 lstat
                                                                            299 lstat
                                                                    1 -[NSPathStore2 stringByResolvingSymlinksInPath]
                                                                      1 -[NSPathStore2 _stringByResolvingSymlinksInPathUsingCache:]
                                                                        1 lstat
                                                                          1 lstat
                                                                  197 -[NSFileManager(SapphireExtensions) isDirectory:]
                                                                    197 -[NSFileManager(SapphireExtensions) hasVIDEO_TS:]
                                                                      197 -[NSFileManager fileExistsAtPath:isDirectory:]
                                                                        197 lstat
                                                                          197 lstat
                                                                  3 +[NSFileAttributes attributesAtPath:traverseLink:]
                                                                    3 listxattr
                                                                      3 listxattr
    500 Thread_1403
      500 _pthread_body
        500 AMFDRMHelper_ComponentDispatch
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_1503
      500 _pthread_body
        500 HDCPMonitorThreadProc
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_1603
      500 _pthread_body
        500 wait4
          500 wait4
    500 Thread_1703
      500 _pthread_body
        500 0x7d77d8
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_1803
      500 _pthread_body
        500 0x182cf
          500 0x18c28
            500 semaphore_wait_signal_trap
              500 semaphore_wait_signal_trap
    500 Thread_1903
      500 _pthread_body
        500 select
          500 select
    500 Thread_1a03
      500 _pthread_body
        500 forkThreadForFunction
          500 -[ATVHIDThread(Private) _hidThreadLoop]
            500 -[NSRunLoop run]
              500 -[NSRunLoop runMode:beforeDate:]
                500 CFRunLoopRunInMode
                  500 CFRunLoopRunSpecific
                    500 mach_msg_trap
                      500 mach_msg_trap
    500 Thread_1b03
      500 _pthread_body
        500 forkThreadForFunction
          500 +[NSURLConnection(NSURLConnectionInternal) _resourceLoadLoop:]
            500 CFRunLoopRunInMode
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_1c03
      500 _pthread_body
        500 0x539d5
          500 0x53aa9
            500 accept
              500 accept
    500 Thread_1d03
      500 _pthread_body
        500 0x539d5
          500 0x53aa9
            500 accept
              500 accept
    500 Thread_1e03
      500 _pthread_body
        500 0x27074
          500 0x27292
            500 0x273c5
              500 semaphore_timedwait_signal_trap
                500 semaphore_timedwait_signal_trap
    500 Thread_1f03
      500 _pthread_body
        500 0x27074
          500 0x27292
            500 0x273c5
              500 semaphore_timedwait_signal_trap
                500 semaphore_timedwait_signal_trap
    500 Thread_2003
      500 _pthread_body
        500 forkThreadForFunction
          500 +[NSURLCache _diskCacheSyncLoop:]
            500 CFRunLoopRunInMode
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_2103
      500 _pthread_body
        500 wait4
          500 wait4
    500 Thread_2203
      500 _pthread_body
        500 0x7d77d8
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_2303
      500 _pthread_body
        500 ReadSchedulerThreadEntryPoint
          500 TSWaitOnSemaphoreCommon
            500 semaphore_timedwait_signal_trap
              500 semaphore_timedwait_signal_trap
    500 Thread_2403
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            500 -[NSConditionLock lockWhenCondition:beforeDate:]
              500 F_CONDITION_WAIT_TIMEOUT
                500 semaphore_timedwait_signal_trap
                  500 semaphore_timedwait_signal_trap
    500 Thread_2503
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            500 -[NSConditionLock lockWhenCondition:beforeDate:]
              500 F_CONDITION_WAIT_TIMEOUT
                500 semaphore_timedwait_signal_trap
                  500 semaphore_timedwait_signal_trap
    500 Thread_2603
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            500 -[NSConditionLock lockWhenCondition:beforeDate:]
              500 F_CONDITION_WAIT_TIMEOUT
                500 semaphore_timedwait_signal_trap
                  500 semaphore_timedwait_signal_trap
    500 Thread_2703
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            500 -[NSConditionLock lockWhenCondition:beforeDate:]
              500 F_CONDITION_WAIT_TIMEOUT
                500 semaphore_timedwait_signal_trap
                  500 semaphore_timedwait_signal_trap
    500 Thread_2803
      500 _pthread_body
        500 CVDisplayLink::runIOThread()
          500 CVDisplayLink::waitUntil(unsigned long long)
            500 semaphore_timedwait_signal_trap
              500 semaphore_timedwait_signal_trap

Total number in stack (recursive counted multiple, when >=5):
        23       _pthread_body
        10       CFRunLoopRunSpecific
        9       mach_msg_trap
        8       forkThreadForFunction
        8       semaphore_timedwait_signal_trap
        5       CFRunLoopRun
        5       CFRunLoopRunInMode

Sort by top of stack, same collapsed (when >= 5):
        mach_msg_trap        4500
        semaphore_timedwait_signal_trap        4000
        accept        1000
        wait4        1000
        select        500
        semaphore_wait_signal_trap        500
        lstat        497

Second run of sample while hung on different directory... 

Analysis of sampling pid 220 every 10.000000 milliseconds
Call graph:
    500 Thread_0133
      500 0xe0769
        500 0xe0842
          500 0x5d6b
            500 -[BRAppManager run]
              500 CFRunLoopRunInMode
                500 CFRunLoopRunSpecific
                  500 _handler
                    500 -[BREventManager(EventHandling) _handler]
                      500 0x9c609
                        500 -[BRControl brEventAction:]
                          500 -[BRControllerStack brEventAction:]
                            500 -[BRControl brEventAction:]
                              500 -[SapphireBrowser brEventAction:]
                                500 -[SapphireMediaMenuController brEventAction:]
                                  500 -[BRMediaMenuController brEventAction:]
                                    500 -[BRController brEventAction:]
                                      500 -[BRControl brEventAction:]
                                        500 -[BRListControl brEventAction:]
                                          500 -[BRInvocationSelectionHandler handleSelectionForControl:]
                                            500 -[NSInvocation invoke]
                                              500 objc_msgSendv
                                                500 -[BRMenuController(Deprecated) _itemSelected:]
                                                  500 -[SapphireBrowser itemSelected:]
                                                    500 -[BRControllerStack(TransactionEngine) _processTransactions]
                                                      500 -[BRControllerStack(TransactionEngine) _processPushTransaction:]
                                                        500 -[SapphireBrowser wasPushed]
                                                          500 -[SapphireMediaMenuController wasPushed]
                                                            500 -[SapphireBrowser doInitialPush]
                                                              500 -[SapphireDirectoryMetaData reloadDirectoryContents]
                                                                500 -[SapphireDirectoryMetaData rescanDirWithExistingDirs:files:symDirs:symFiles:]
                                                                  401 -[NSFileManager(SapphireExtensions) acceptFilePath:]
                                                                    401 -[NSPathStore2 stringByResolvingSymlinksInPath]
                                                                      401 -[NSPathStore2 _stringByResolvingSymlinksInPathUsingCache:]
                                                                        401 lstat
                                                                          401 lstat
                                                                  99 +[NSFileAttributes attributesAtPath:traverseLink:]
                                                                    99 listxattr
                                                                      99 listxattr
    500 Thread_1203
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRDisplayManager(DisplayNotificationsPrivate) _windowServerCallbackHandler]
            500 CFRunLoopRun
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_1303
      500 _pthread_body
        500 CAPThread::Entry(CAPThread*)
          500 HALRunLoop::OwnThread(void*)
            500 CFRunLoopRunInMode
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_1403
      500 _pthread_body
        500 AMFDRMHelper_ComponentDispatch
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_1503
      500 _pthread_body
        500 HDCPMonitorThreadProc
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_1603
      500 _pthread_body
        500 wait4
          500 wait4
    500 Thread_1703
      500 _pthread_body
        500 0x7d77d8
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_1803
      500 _pthread_body
        500 0x182cf
          500 0x18c28
            500 semaphore_wait_signal_trap
              500 semaphore_wait_signal_trap
    500 Thread_1903
      500 _pthread_body
        500 select
          500 select
    500 Thread_1a03
      500 _pthread_body
        500 forkThreadForFunction
          500 -[ATVHIDThread(Private) _hidThreadLoop]
            500 -[NSRunLoop run]
              500 -[NSRunLoop runMode:beforeDate:]
                500 CFRunLoopRunInMode
                  500 CFRunLoopRunSpecific
                    500 mach_msg_trap
                      500 mach_msg_trap
    500 Thread_1b03
      500 _pthread_body
        500 forkThreadForFunction
          500 +[NSURLConnection(NSURLConnectionInternal) _resourceLoadLoop:]
            500 CFRunLoopRunInMode
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_1c03
      500 _pthread_body
        500 0x539d5
          500 0x53aa9
            500 accept
              500 accept
    500 Thread_1d03
      500 _pthread_body
        500 0x539d5
          500 0x53aa9
            500 accept
              500 accept
    500 Thread_1e03
      500 _pthread_body
        500 0x27074
          500 0x27292
            500 0x273c5
              500 semaphore_timedwait_signal_trap
                500 semaphore_timedwait_signal_trap
    500 Thread_1f03
      500 _pthread_body
        500 0x27074
          500 0x27292
            500 0x273c5
              500 semaphore_timedwait_signal_trap
                500 semaphore_timedwait_signal_trap
    500 Thread_2003
      500 _pthread_body
        500 forkThreadForFunction
          500 +[NSURLCache _diskCacheSyncLoop:]
            500 CFRunLoopRunInMode
              500 CFRunLoopRunSpecific
                500 mach_msg_trap
                  500 mach_msg_trap
    500 Thread_2103
      500 _pthread_body
        500 wait4
          500 wait4
    500 Thread_2203
      500 _pthread_body
        500 0x7d77d8
          500 CFRunLoopRun
            500 CFRunLoopRunSpecific
              500 mach_msg_trap
                500 mach_msg_trap
    500 Thread_2303
      500 _pthread_body
        500 ReadSchedulerThreadEntryPoint
          500 TSWaitOnSemaphoreCommon
            500 semaphore_timedwait_signal_trap
              500 semaphore_timedwait_signal_trap
    500 Thread_2403
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            491 -[NSConditionLock lockWhenCondition:beforeDate:]
              491 F_CONDITION_WAIT_TIMEOUT
                491 semaphore_timedwait_signal_trap
                  491 semaphore_timedwait_signal_trap
            9 -[NSRunLoop runMode:beforeDate:]
              9 CFRunLoopRunInMode
                9 CFRunLoopRunSpecific
                  9 mach_msg_trap
                    9 mach_msg_trap
    500 Thread_2503
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            490 -[NSConditionLock lockWhenCondition:beforeDate:]
              490 F_CONDITION_WAIT_TIMEOUT
                490 semaphore_timedwait_signal_trap
                  490 semaphore_timedwait_signal_trap
            10 -[NSRunLoop runMode:beforeDate:]
              10 CFRunLoopRunInMode
                10 CFRunLoopRunSpecific
                  10 mach_msg_trap
                    10 mach_msg_trap
    500 Thread_2603
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            500 -[NSConditionLock lockWhenCondition:beforeDate:]
              500 F_CONDITION_WAIT_TIMEOUT
                500 semaphore_timedwait_signal_trap
                  500 semaphore_timedwait_signal_trap
    500 Thread_2703
      500 _pthread_body
        500 forkThreadForFunction
          500 -[BRTaskManager(Private) _processTasks]
            490 -[NSConditionLock lockWhenCondition:beforeDate:]
              490 F_CONDITION_WAIT_TIMEOUT
                490 semaphore_timedwait_signal_trap
                  490 semaphore_timedwait_signal_trap
            10 -[NSRunLoop runMode:beforeDate:]
              10 CFRunLoopRunInMode
                10 CFRunLoopRunSpecific
                  10 mach_msg_trap
                    10 mach_msg_trap
    500 Thread_2803
      500 _pthread_body
        500 CVDisplayLink::runIOThread()
          500 CVDisplayLink::waitUntil(unsigned long long)
            500 semaphore_timedwait_signal_trap
              500 semaphore_timedwait_signal_trap

Total number in stack (recursive counted multiple, when >=5):
        23       _pthread_body
        13       CFRunLoopRunSpecific
        12       mach_msg_trap
        8       CFRunLoopRunInMode
        8       forkThreadForFunction
        8       semaphore_timedwait_signal_trap
        5       CFRunLoopRun

Sort by top of stack, same collapsed (when >= 5):
        mach_msg_trap        4529
        semaphore_timedwait_signal_trap        3971
        accept        1000
        wait4        1000
        select        500
        semaphore_wait_signal_trap        500
        lstat        401
        listxattr        99

11/14/09 07:43:22 changed by gbooker

  • status changed from new to closed.
  • resolution set to fixed.

(In [958]) Don't need to resolve symlinks when checking whether to accept a file path since the filemanager routines will resolve them anyway. Additionally, re-ordered checks so it hits the disk less often and don't check for VIDEO_TS dirs since anything passing that test would have passed the directory test already. Fixes #324

(follow-up: ↓ 7 ) 11/14/09 07:45:10 changed by gbooker

  • milestone deleted.

I should add, every single point where Sapphire is frozen is in accessing your SMB mount. You have a really slow SMB server and that's the real problem (on top of the fact that SMB is a lousy file sharing protocol in the first place). The above commit will help, but the best solution is a better file server.

(in reply to: ↑ 6 ) 11/14/09 16:37:26 changed by ndobson

Replying to gbooker:

I should add, every single point where Sapphire is frozen is in accessing your SMB mount. You have a really slow SMB server and that's the real problem (on top of the fact that SMB is a lousy file sharing protocol in the first place). The above commit will help, but the best solution is a better file server.

Man I feel dumb and thanks for reminding me... My smb server is an Airport-Extreme running 7.4.2 firmware (I know I should move all this to my linux box.) When that firmware update first came out i had performance issues with it so i reverted back to 7.4.1... well time passed and i forgot all about it and upgraded to 7.4.2 again like a dumbass.

So now I reverted back to 7.4.1 again and the difference is huge. No more hangups. Sorry to bother you with this.

11/14/09 20:18:26 changed by gbooker

Well, as you can see, you did point out some slow code in terms of accessing the file system. If you are using an Airport-Extreme, you should be able to use AFP. It should be faster than SMB (b/c Apple cares about that code more on both sides).

BTW, I agree you should move to a linux box. My father's Airport Extreme cause file-system damage to every disk he had connected, and even caused the occasional file to disappear immediately after coping to the disk. I personally use my AppleTV as the server and connect disks via USB.