[4.1.8-T5]: SPARC CNID DB error under Lion AFP [Resolved]

DeltaTee wrote:
After updating my ReadyNAS NV to RAIDiator 4.1.8-T5 I get the following error when attempting to connect to it via AFP in OSX Lion: "Something wrong with the volume's CNID DB, using temporary CNID DB instead.Check server messages for details. Switching to read-only mode." Connecting with SMB works properly.

Sorry for the late reply. The AFP service in 4.1.8-T5 updates the CNIB DB on first access, and during that access, writes are disabled on the share. If you have a ton of files in that share, it may take awhile to update the DB. Once the update process is complete, you should have full read/write access to the share.

yoh-dah wrote:
Sorry for the late reply. The AFP service in 4.1.8-T5 updates the CNIB DB on first access, and during that access, writes are disabled on the share. If you have a ton of files in that share, it may take awhile to update the DB. Once the update process is complete, you should have full read/write access to the share.

I tried installing this update on my ReadyNAS NV+ and was unable to access the AFP share using Snow Leopard. There was no error message, but the Finder hung with the spinning pinwheel. Checking the logs, I found many occurrences of this in the system log:

Jul 22 22:21:11 macpro kernel[0]: Secondary Reconnect succeeded /Volumes/NAS
Jul 22 22:21:16 macpro KernelEventAgent[94]: tid 00000000 received event(s) VQ_NOTRESP (1)
Jul 22 22:21:17 macpro kernel[0]: Secondary Reconnect succeeded /Volumes/NAS
Jul 22 22:21:23 macpro KernelEventAgent[94]: tid 00000000 received event(s) VQ_NOTRESP (1)
...repeat...

The kernel log kept repeating:

Jul 22 22:25:45 macpro kernel[0]: Secondary Reconnect succeeded /Volumes/NAS
Jul 22 22:25:45 macpro kernel[0]: ASP_TCP CancelOneRequest:  cancelling slot 111 error 35 reqID 281 flags 0x29 afpCmd 0x4B so 0xffffff801d512000
Jul 22 22:25:45 macpro kernel[0]: ASP_TCP CancelOneRequest:  cancelling slot 112 error 35 reqID 282 flags 0x29 afpCmd 0x11 so 0xffffff801d512000
Jul 22 22:25:45 macpro kernel[0]: ASP_TCP CancelOneRequest:  cancelling slot 113 error 35 reqID 283 flags 0x29 afpCmd 0x11 so 0xffffff801d512000
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  get the reconnect token
Jul 22 22:25:45 macpro kernel[0]: ASP_TCP CancelOneRequest:  cancelling slot 116 error 32 reqID 293 flags 0x9 afpCmd 0x40 so 0xffffff801d512000
Jul 22 22:25:45 macpro kernel[0]: ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 25 on so 0xffffff801d512000
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  GetReconnectToken failed 32 /Volumes/NAS
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect started /Volumes/NAS prevTrigger 25 currTrigger 26
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  doing reconnect on /Volumes/NAS
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  posting to KEA EINPROGRESS for /Volumes/NAS
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  Max reconnect time: 30 secs, Connect timeout: 15 secs for /Volumes/NAS
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  connect to the server /Volumes/NAS
Jul 22 22:25:45 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  Logging in with uam 8 /Volumes/NAS
Jul 22 22:25:46 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  Restoring session /Volumes/NAS
Jul 22 22:25:51 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  Primary Reconnect failed 22 on /Volumes/NAS
Jul 22 22:25:51 macpro kernel[0]: AFP_VFS afpfs_DoReconnect:  trying Secondary Reconnect on /Volumes/NAS
...repeat...

At this point I downgraded my ReadNAS NV+ back to 4.1.7 and rebooted my Mac. Was this the same CNID DB issue that I needed to wait out? My volume is quite large at 6TB with many files.

Thanks,
-Mike

yoh-dah wrote:
Sorry for the late reply. The AFP service in 4.1.8-T5 updates the CNIB DB on first access, and during that access, writes are disabled on the share. If you have a ton of files in that share, it may take awhile to update the DB. Once the update process is complete, you should have full read/write access to the share.

I can just try waiting then (I don't think I had done that one yet). I would assume that disabling/re-enabling the afp on the volume resets the clock. How long is quite a while? Hours? Minutes? Days? Weeks? Will I need to reconnect the share when it is finished, or will it automatically show up read-write? Is there a way that I can check on the ReadyNAS to see the progress (I have ssh enabled).

DeltaTee wrote:
Will I need to reconnect the share when it is finished, or will it automatically show up read-write?

While I cannot be 100% certain - that would be advisable. In the past, any changes made to the AFP service have tended to require the client to disconnect & reconnect to detect those changes, so the cautious approach would be to assume the same requirement for this update. It could also serve as an indication that the update is complete (ie you should not get the error on reconnection if the update is done)

The 4.2.19 beta firmware (x86 only) fixed this issue finally for me. I had rebooted both the NAS and my mac many times over the last week since upgrading to 4.2.18 and I never had access to one of my shares over AFP. Installed the 4.2.19 beta today and according to the release notes it updates all CNID databases during the firmware upgrade. This has finally resolved it for me. Hopefully the same fix can go into a beta firmware for sparc to help the rest of you.

yoh-dah wrote:
Sorry for the late reply. The AFP service in 4.1.8-T5 updates the CNIB DB on first access, and during that access, writes are disabled on the share. If you have a ton of files in that share, it may take awhile to update the DB. Once the update process is complete, you should have full read/write access to the share.

I updated my ReadyNAS NV to beta. It has 4 shares. 3 shares mount without the error now 8) , but one share, which has A LOT of files (pictures (about 30 000 files), music (about 80 gig), and movies, all in all 300 gig or more) is still producing this error. I waited for some 12 hours, then decided that the AFP service failed to update the CNIB DB on this share, and flushed the NAS again with the same 4.1.8 beta firmware, hoping to restart the update process. its been over 20 hours now, still, getting the same error.

what's your advice, Yoh-dah, wait for another 24 hours (would it be advisable to unmount all the shares in the meantime?), or, maybe there is a way to trigger the AFP service update?

thanks in advance,

Vasily

Vasa,

It should be fix in next release.

After installing the T9 beta (released today), my ReadyNAS NV appears to be happy.

Find the beta forum here: viewtopic.php?f=17&t=55155

The T9 beta fixed it for me too :). Thanks!

Welcome and thanks for the update..