Ticket #324 (closed Defect: fixed)

Opened 10 months ago

Last modified 10 months ago

Extremely slow file browsing via smb mount

Reported by: ndobson Owned by:
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

  Changed 10 months ago by gbooker

  • milestone set to Awaiting User Feedback

BugReporting

  Changed 10 months ago 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

  Changed 10 months ago by gbooker

BugReporting, number 5.

  Changed 10 months ago 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

  Changed 10 months ago 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   Changed 10 months ago by gbooker

  • milestone Awaiting User Feedback 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   Changed 10 months ago 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.

  Changed 10 months ago 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.

Note: See TracTickets for help on using tickets.