Warum kommt "kernel[0]: AFP_VFS afpfs_vnop_ioctl: afpfs_FindForkRef failed -1" von MusicBrainz Picard, wenn ich auf meinen AFP NAS-Server schreibe?

Ich habe einen sehr seltsamen Fehler. Die App MusicBrainz Picard 1.3.2 spuckt beim Schreiben von modifizierten Audiodateien auf einen Network Attached Storage (NAS_-Dateiserver) manchmal Hunderte dieser Nachricht aus. Während sie ausspuckt, hängt sie mit einem sich drehenden Strandball, bis ich sie erzwinge.

Was verursacht dieses Hängen? Wie kann ich es verhindern? Wenn das Aufhängen auftritt, was kann ich tun, um meinen Computer oder Dateiserver oder die Verbindung zurückzusetzen, damit das Aufhängen nicht mehr auftritt?

Ich werde Antworten positiv bewerten, die sogar Aufschluss darüber geben können, worauf afpfs_FindForkRefsich diese beziehen. Wenn ich nach diesem Begriff suche, erhalte ich aus irgendeinem Grund null Treffer in den Suchmaschinen Google und DuckDuckGo. Ich vermute, "afpfs" steht für "Apple Filing Protocol File System".

Hier ist das Nachrichtenprotokoll um die Zeit, zu der ich das Beenden der hängenden App erzwinge:

....
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

Beachten Sie die Meldung „Kernel hat 500 Protokollmeldungen pro Sekunde überschritten“. Wenn diese App hängt, scheint es, als ob sie diese Protokollnachricht so schnell generiert, wie es ihre innere Schleife zulässt.

Dies ist heute nicht vorgekommen, da ich an anderen Daten gearbeitet habe. Es tritt jetzt auf. Es ist vor ein paar Tagen aufgetreten, mit früheren Daten. In der Zwischenzeit hat etwas es gestoppt.

Andere Apps provozieren dieses Problem derzeit nicht. Wenn ich diese App auf meine lokale Festplatte anstatt auf den NAS-Dateiserver schreiben lasse, tritt das Problem nicht auf. Wenn ich den Dateiserver trenne und wieder verbinde, tritt das Problem erneut auf. Wenn ich in der Vergangenheit sowohl meinen Mac als auch den Dateiserver neu gestartet habe, ist das Problem erneut aufgetreten, aber ich habe das diesmal nicht versucht.

Mein Computer : MacBook Pro Retina, Mitte 2014, mit OS X Yosemite 10.10.5

Die App : MusicBrainz Picard 1.3.2 , die Audiodateien Metadaten hinzufügt und die Dateien in ein Zielverzeichnis verschiebt.

Der Quellpfad : Pfad einer Musikdatei auf dem Dateiserver, zB 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 Zeichen)

Der Zielpfad : Pfad einer modifizierten Musikdatei auf dem Dateiserver, zB 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 Zeichen)

Der Dateiserver : ein QNAP TS-219P , etwa 5 Jahre alt

Die Verbindung : über einen Eintrag im linken Bereich eines Finder-Fensters, „myServer(AFP)“, mit einem Server-Box-Bild als Vorschau. WENN ich mit der rechten Maustaste auf dieses Symbol klicke und „Get Info“ aus dem Popup-Menü auswähle, erscheint ein Info-Fenster. Darin steht unter „Allgemeine Informationen“ „Art: Mac, Wo: Netzwerk“. „Weitere Informationen“ steht (ein sich drehendes Symbol) mit der Meldung „Fetching...“.

Das Volume : Der NAS-Server verfügt über mehrere Dateisystemvolumes. Der fragliche Band trägt den Namen „Qmultimedia“, mit einer Plattenhülle und einem Cartoon von drei Humanoiden als Vorschau. WENN ich mit der rechten Maustaste auf dieses Symbol klicke und „Get Info“ aus dem Popup-Menü auswähle, erscheint ein Info-Fenster. Darin heißt es unter „Allgemein“:

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)

Der Hang-Bericht : Es gibt viel im Hang-Bericht /Library/Logs/DiagnosticReports/MusicBrainz Picard_2016-09-03-233838_MyMac.hang, aber hier sind einige Highlights:

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
....

Unten verschachtelte Einträge hndl_unix_scall64scheinen mit Protokollnachrichten zu tun zu haben, also vermute ich, dass die Nachrichten daher stammen. Ich vermute, dass das Symbol hndl_unix_scall64in der Nähe ist, wo die Anrufe schief gehen.

Aktualisiert am 04.09.2016 : Beispiele für Original- und Zielpfade hinzugefügt. Fügen Sie auch diesen Diagnosebefund hinzu. Wenn ich das interne Skript von Picard verwende, um die Länge seiner Pfadsegmente auf 160 Zeichen zu kürzen, ist das Speichern der Datei erfolgreich. Die afpfs_FindForkRef failed -1werden immer noch zu Hunderten in das Konsolenprotokoll gegossen, aber nur für ein paar Sekunden. Dann hören sie auf, und Picard hängt nicht. Daher kann die Gesamtlänge des Pfads oder die Länge von Abschnitten des Pfads relevant sein.

Antworten (1)

Aus dem Experimentieren heraus, hier ist eine Problemumgehung.

Verwenden Sie das Skript von Picard , um die Länge jedes Segments des Pfads zu begrenzen, in den Sie die Musikdateien umbenennen. Dies verhindert, dass der Hang lange anhält, was eine der Fragen beantwortet.

Verwenden Sie in den Dateibenennungsoptionen von Picard die Skriptfunktion, $truncate(field,length)um die Größe jedes Pfadsegments zu begrenzen. Also statt:

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

Verwenden Sie dies (und das Limit 160 ist willkürlich; 300 und 100 scheinen auch zu funktionieren):

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

Es gibt keine Beweise dafür, dass das Hängen ein staatliches Problem ist. Es scheint reproduzierbar durch das Verhalten der Anwendung provoziert zu werden. Abgesehen von der Änderung des von Picard ausgeführten Skripts ist es also nicht erforderlich, den Computer oder Server zurückzusetzen. Damit ist eine weitere Frage beantwortet.

Dies beantwortet immer noch nicht, was dieses Hängen verursacht und wie es an der Ursache verhindert werden kann.

Ich denke nicht, dass dies eine sehr zufriedenstellende Antwort ist, insbesondere weil sie weder die Ursache noch die Bedeutung von identifiziert afpfs_FindForkRef. Es gibt anderen jedoch eine Problemumgehung und legt eine niedrigere Messlatte für andere Antworten fest.
Warum kommt "kernel[0]: AFP_VFS afpfs_vnop_ioctl: afpfs_FindForkRef failed -1" von MusicBrainz Picard, wenn ich auf meinen AFP NAS-Server schreibe?
AntwortenHierDatenschutz-Bestimmungen1y, 0v