Почему "kernel[0]: AFP_VFS afpfs_vnop_ioctl: afpfs_FindForkRef failed -1" выливается из MusicBrainz Picard при записи на мой сервер AFP NAS?

У меня очень странный провал. Приложение MusicBrainz Picard 1.3.2 при записи измененных аудиофайлов в сетевое хранилище (файловый сервер NAS_) иногда выдает сотни таких сообщений. Во время выдачи оно зависает с вращающимся пляжным мячом, пока я не выйду из него принудительно.

Что вызывает это зависание? Как я могу предотвратить это? Когда происходит зависание, что я могу сделать, чтобы перезагрузить компьютер, файловый сервер или соединение, чтобы зависание прекратилось?

Я буду голосовать за ответы, которые могут даже пролить свет на то, к чему afpfs_FindForkRefотносится. По какой-то причине, когда я ищу этот термин, я не получаю никаких результатов в поисковых системах Google и DuckDuckGo. Я предполагаю, что «afpfs» означает «Файловая система Apple Filing Protocol».

Вот журнал сообщений примерно в то время, когда я принудительно выхожу из зависшего приложения:

....
2016-09-03 23:38:15.000 kernel[0]: AFP_VFS afpfs_vnop_ioctl:  afpfs_FindForkRef failed -1
2016-09-03 23:38:15.000 kernel[0]: AFP_VFS afpfs_vnop_ioctl:  afpfs_FindForkRef failed -1
2016-09-03 23:38:15.000 kernel[0]: AFP_VFS afpfs_vnop_ioctl:  afpfs_FindForkRef failed -1
2016-09-03 23:38:15.000 kernel[0]: *** kernel exceeded 500 log message per second limit  -  remaining messages this second discarded ***
2016-09-03 23:38:15.881 com.apple.xpc.launchd[1]: (org.musicbrainz.picard.79268[5403]) Service exited due to signal: Killed: 9
2016-09-03 23:38:20.927 SystemUIServer[1443]: Attempt to use XPC with a MachService that has HideUntilCheckIn set. This will result in unpredictable behavior: com.apple.backupd.status.xpc
2016-09-03 23:38:38.069 spindump[1708]: Saved hang report for MusicBrainz Picard version 1.3.2 (Picard 1.3.2) to /Library/Logs/DiagnosticReports/MusicBrainz Picard_2016-09-03-233838_MyMac.hang

Обратите внимание на сообщение «ядро превысило 500 сообщений журнала в секунду». Когда это приложение зависает, кажется, что оно генерирует это сообщение журнала так быстро, как позволяет его внутренний цикл.

Этого не произошло ранее сегодня, работая с другими данными. Это происходит сейчас. Это произошло несколько дней назад, по предыдущим данным. Тем временем что-то заставило его остановиться.

Другие приложения не вызывают эту проблему прямо сейчас. Если это приложение записывает данные на мой локальный диск, а не на файловый сервер NAS, проблема не возникает. Если я отключу и снова подключу файловый сервер, проблема возникнет снова. В прошлом, когда я перезапускал свой Mac и файловый сервер, проблема повторялась, но на этот раз я не пробовал.

Мой компьютер : MacBook Pro Retina, середина 2014 г., работающий под управлением OS X Yosemite 10.10.5.

Приложение : MusicBrainz Picard 1.3.2 , которое добавляет метаданные к аудиофайлам и перемещает файлы в целевой каталог.

Исходный путь : путь к музыкальному файлу на файловом сервере, например u'/Volumes/Qmultimedia/Music/_inbox/_tracks/Vancouver Academy of Music Symphony Orchestra/VAM Mozart Requiem 2014/02 Symphony No. 8 D. 759 "Unfinished"- I. Allegro moderato.flac'(175 символов)

Путь назначения : путь к измененному музыкальному файлу на файловом сервере, например u'/Volumes/Qmultimedia/Music/master_tagged_files/Mozart, Wolfgang Amadeus, Schubert, Franz; Vancouver Academy of Music Symphony Orchestra, Dala, Leslie, Wood, Caitlin, Froese, Laurelle Jade, Rupolo, Rocco, Read, Zachary, Vancouver Bach Choir/Mozart Requiem _ Schubert _Unfinished_ Symphony/02 Symphony No. 8 in B minor, D. 759 _Unfinished__ I. Allegro moderato.flac'(363 символа)

Файловый сервер : QNAP TS-219P , возраст около 5 лет.

Соединение : через запись в левой панели окна Finder «myServer (AFP)» с изображением окна сервера в качестве предварительного просмотра. КОГДА я щелкаю правой кнопкой мыши по этому значку и выбираю «Получить информацию» во всплывающем меню, появляется информационное окно. В нем «Общая информация» гласит: «Вид: Mac, Где: Сеть». «Дополнительная информация» гласит (вращающийся значок) с сообщением «Выборка…».

Том : сервер NAS имеет несколько томов файловой системы. Рассматриваемый том называется «Qmultimedia», с коробкой для диска и карикатурой на трех гуманоидов в качестве превью. КОГДА я щелкаю правой кнопкой мыши по этому значку и выбираю «Получить информацию» во всплывающем меню, появляется информационное окно. В нем «Генерал» гласит:

Server: afp://Gemini(AFP)._afpovertcp._tcp.local/Qmultimedia
Created: Sunday, 21. December, 2014 at 14:18
Modified: Today, 00:48
Format: AppleShare
Capacity: 2.95 TB
Available: 1.48 TB
Used: 1,474,284,388,352 bytes (1.47 TB on disk)

Отчет о зависании : в отчете о зависании, /Library/Logs/DiagnosticReports/MusicBrainz Picard_2016-09-03-233838_MyMac.hang, много всего, но вот некоторые основные моменты:

Event:           hang
Duration:        4.70s (process was unresponsive for 31 seconds before sampling)
Steps:           48 (100ms sampling interval)

Heaviest stack for the main thread of the target process:
  48  start + 52 (MusicBrainz Picard + 3044) [0x100000be4]
  48  main + 650 (MusicBrainz Picard + 4474) [0x10000117a]
  48  py2app_main + 2683 (MusicBrainz Picard + 10075) [0x10000275b]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 943050) [0x1040353ca]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 942382) [0x10403512e]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 792742) [0x1040108a6]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 792454) [0x104010786]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 785344) [0x10400ebc0]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 792454) [0x104010786]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 789242) [0x10400fafa]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 792454) [0x104010786]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 785344) [0x10400ebc0]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 792454) [0x104010786]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 787402) [0x10400f3ca]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 784253) [0x10400e77d]
  48  ??? (<F57E8887-372A-E630-588B-1148CCA29919> + 3464844) [0x107efbe8c]
  48  ??? (<4172EABD-46BE-2722-C849-F7FB5632DED2> + 1324428) [0x10918158c]
  48  ??? (<4172EABD-46BE-2722-C849-F7FB5632DED2> + 1314468) [0x10917eea4]
  48  ??? (<4172EABD-46BE-2722-C849-F7FB5632DED2> + 1313524) [0x10917eaf4]
  48  ??? (<CD803C71-F94D-524C-1A39-07D1A339A0F0> + 272000) [0x108485680]
  48  -[NSApplication run] + 594 (AppKit + 551667) [0x7fff837caaf3]
  48  -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] + 346 (AppKit + 593496) [0x7fff837d4e58]
  48  _DPSNextEvent + 978 (AppKit + 596139) [0x7fff837d58ab]
  48  _BlockUntilNextEventMatchingListInModeWithFilter + 71 (HIToolbox + 205099) [0x7fff8f07812b]
  48  ReceiveNextEventCommon + 179 (HIToolbox + 205294) [0x7fff8f0781ee]
  48  RunCurrentEventLoopInMode + 235 (HIToolbox + 206191) [0x7fff8f07856f]
  48  CFRunLoopRunSpecific + 296 (CoreFoundation + 465880) [0x7fff887abbd8]
  48  __CFRunLoopRun + 927 (CoreFoundation + 467391) [0x7fff887ac1bf]
  48  __CFRunLoopDoSources0 + 269 (CoreFoundation + 469901) [0x7fff887acb8d]
  48  __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17 (CoreFoundation + 526849) [0x7fff887baa01]
  48  ??? (<4172EABD-46BE-2722-C849-F7FB5632DED2> + 1323008) [0x109181000]
  48  ??? (<4172EABD-46BE-2722-C849-F7FB5632DED2> + 1317852) [0x10917fbdc]
  48  ??? (<F57E8887-372A-E630-588B-1148CCA29919> + 3461518) [0x107efb18e]
  48  ??? (<CD803C71-F94D-524C-1A39-07D1A339A0F0> + 588900) [0x1084d2c64]
  48  ??? (<CD803C71-F94D-524C-1A39-07D1A339A0F0> + 562669) [0x1084cc5ed]
  48  ??? (<F57E8887-372A-E630-588B-1148CCA29919> + 3465277) [0x107efc03d]
  48  ??? (<CFFC31D5-41BF-BC16-2650-C745627427E7> + 26259) [0x104715693]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 933631) [0x104032eff]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 759914) [0x10400886a]
  48  ??? (<96E177D6-BA68-399D-7325-FAA0DD7247EB> + 1026148) [0x104049864]
  48  __psynch_cvwait + 10 (libsystem_kernel.dylib + 90422) [0x7fff8275b136]
 *48  psynch_cvcontinue + 0 (pthread + 26910) [0xffffff7f80f9991e]
....
  Thread 0x13ac3a     48 samples (1-48)   priority 31         cpu time 4.697s
  <thread QoS legacy, boosted, received importance donation from WindowServer [189], IO policy important>
  48  thread_start + 13 (libsystem_pthread.dylib + 5101) [0x7fff8dd113ed] 1-48
    48  _pthread_start + 176 (libsystem_pthread.dylib + 16343) [0x7fff8dd13fd7] 1-48
      48  _pthread_body + 131 (libsystem_pthread.dylib + 16474) [0x7fff8dd1405a] 1-48
        48  ??? (<4172EABD-46BE-2722-C849-F7FB5632DED2> + 161492) [0x1090656d4] 1-48
....
                                                                    48  __fcntl + 10 (libsystem_kernel.dylib + 88482) [0x7fff8275a9a2] 1-48
                                                                     *34  hndl_unix_scall64 + 22 (kernel + 2311718) [0xffffff8000434626] 1-34
....
                                                                     *1   hndl_unix_scall64 + 10 (kernel + 2311706) [0xffffff800043461a] (running) 35
                                                                     *13  hndl_unix_scall64 + 22 (kernel + 2311718) [0xffffff8000434626] 36-48
....

Записи, вложенные ниже, hndl_unix_scall64похоже, связаны с сообщениями журнала, поэтому я предполагаю, что сообщения поступают оттуда. Я предполагаю, что этот символ hndl_unix_scall64находится рядом с тем местом, где вызовы идут не так, как надо.

Обновлено 4 сентября 2016 г .: добавлены примеры исходного и целевого путей. Также добавьте этот диагноз. Когда я использую внутренний сценарий Picard для усечения длины его сегментов пути до 160 символов, сохранение файла завершается успешно. Они afpfs_FindForkRef failed -1по-прежнему сыплются в лог консоли сотнями, но всего на пару секунд. Затем они останавливаются, и Пикард не виснет. Таким образом, может иметь значение общая длина пути или длина сегментов пути.

Ответы (1)

Из экспериментов, вот обходной путь.

Используйте сценарии Пикарда , чтобы ограничить длину каждого сегмента пути, в который вы переименовываете музыкальные файлы. Это предотвращает длительное зависание, что отвечает на один из вопросов.

В параметрах именования файлов Picard используйте функцию сценария $truncate(field,length), чтобы ограничить размер каждого сегмента пути. Таким образом, вместо:

$if2(%albumartistsort%,%artist%)/%album/ $if($gt(%totaldiscs%,1),%discnumber%)$num(%tracknumber%,2) %title%

используйте это (и ограничение 160 является произвольным; 300 и 100 также работают):

$truncate($if2(%albumartistsort%,%artist%),160)/$truncate(%album%,160)/ $truncate($if($gt(%totaldiscs%,1),%discnumber%)$num(%tracknumber%,2) %title%,160)

Нет никаких доказательств того, что зависание является государственной проблемой. Кажется, это воспроизводимо провоцируется поведением приложения. Таким образом, помимо изменения сценария, который вы запускаете в Picard, нет необходимости перезагружать компьютер или сервер. Это отвечает еще на один из вопросов.

Это все еще не отвечает, что вызывает это зависание и как предотвратить его первопричину.

Я не думаю, что это очень удовлетворительный ответ, особенно потому, что он не определяет причину или значение afpfs_FindForkRef. Тем не менее, это дает другим обходной путь и устанавливает более низкую планку для других ответов.
Почему "kernel[0]: AFP_VFS afpfs_vnop_ioctl: afpfs_FindForkRef failed -1" выливается из MusicBrainz Picard при записи на мой сервер AFP NAS?
СпросиСетьПолитика конфиденциальности1y, 0v