"malformed AppleDouble" and "Input/output error" messages on 3.1.14 #270

mikaku · 2023-04-05T06:32:06Z

Hello,

Following the recommendation of @knight-of-ni in #175, I opened new issue:

I'm seeing these messages:

Dec 22 12:48:25 linux afpd[18995]: parse_entries: bogus eid: 9, off: 50, len: 3760
Dec 22 12:48:25 linux afpd[18995]: ad_header_read(/u/applepublic/XXX/D06037138/._pont-aven-9089-42_w400.jpg): malformed AppleDouble
Dec 22 12:48:25 linux afpd[18995]: ad_header_read_osx(rfpath, ad, &st) failed: Input/output error
Dec 22 12:48:25 linux afpd[18995]: afp_openfork(pont-aven-9089-42_w400.jpg): ad_open: Input/output error

Any idea?

OS: CentOS Linux release 7.9.2009 (Core)

# uname -r
3.10.0-1160.88.1.el7.x86_64

# rpm -q --last netatalk
netatalk-3.1.14-1.el7.x86_64                  Sun 05 Feb 2023 09:13:10 AM CET

The text was updated successfully, but these errors were encountered:

mikaku · 2023-04-05T06:36:16Z

@rdmark

Did the problematic volumes by any chance start out as netatalk2 volumes and then converted to netatalk3 at some point over the years?

These volumes are old, and yes, they were probably created using netatalk2. I remember using the version 2 long time ago. But I don't remember doing a conversion of these volumes.

Perhaps they were converted automagically by netatalk3?

rdmark · 2023-04-08T20:35:15Z

@mikaku This is good context. The running theory is that the added validation as of late has revealed malformed metadata caused by either the conversion from netatalk2 adouble to netatalk3 ea metadata, or some other kind of data corruption over time.

See discussion in #236

mikaku · 2023-04-12T06:10:33Z

@rdmark, thanks for your assistance.

I've ran the command dbd -s on the two volumes and they have shown tons of lines of different types of errors as shown below:

Orphaned AppleDoube file '/u/vol1/.AppleDouble/TA02010000070539.jpg'
Bad AppleDouble "/u/vol1/._TA10020000230418.jpg"
Apr 12 08:02:19.413702 dbd[31036] {ad_open.c:818} (error:ad): ad_header_read_ea("/u/vol2/xxxxxxx"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file.
Apr 12 08:02:20.409216 dbd[31036] {ad_open.c:549} (warn:ad): ad_valid_header_osx("/u/vol2/1D000150741.jpg"): not an adouble:osx file

Do you think it will be safe to run dbd -f on the two volumes?

rdmark · 2023-04-21T20:43:45Z

Are you able to take a backup of the volume before running dbd -f? Given all of the validation errors that we've been seeing, it might be a risky/destructive process.

mikaku · 2023-04-27T06:18:57Z

@rdmark, OK thanks.
Just a small more question: when running dbd -f it's necessary to stop Netatalk? I mean, to not interfere in the process.

rdmark · 2023-04-27T16:09:48Z

@mikaku I would definitely stop netatalk first to avoid any potential race condition when both processes try to operate on the database at the same time.

mikaku · 2023-04-29T08:00:07Z

It seems that dbd can't run if Netatalk is stopped:

# dbd -f vol1
Apr 29 08:53:57.912027 dbd[27049] {cnid_dbd.c:152} (error:CNID): getfd: getsockopt says: Connection refused
Apr 29 08:53:57.912212 dbd[27049] {cnid_dbd.c:152} (error:CNID): getfd: getsockopt says: Connection refused
Apr 29 08:53:57.912259 dbd[27049] {cnid_dbd.c:176} (error:CNID): tsock_getfd: no suitable network config from CNID server (localhost:4700): Connection refused
Apr 29 08:53:57.912289 dbd[27049] {cnid_dbd.c:407} (error:CNID): transmit: connection refused (volume Vol1)
Failed to wipe CNID db

So I did it with Netatalk running and ~~it seems it was fixed~~ still I'm seeing tons of errors like these:

Apr 29 11:26:16.372167 dbd[9402] {ad_open.c:818} (error:ad): ad_header_read_ea("[...]"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file
[...]
Bad AppleDouble "[...]"
[...]

Now I'll wait for Monday to see if users don't have any problem (:crossed_fingers:).

mikaku · 2023-05-10T06:01:54Z

I still see messages like this:

invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file.

Anyway, since they are really low I can live with them.
Thanks.

rdmark · 2023-08-10T17:38:41Z

Reopening this since the original issue was reported by another user in #368

The root cause, I think, is that netatalk is trying to read AD headers from a symlink, which it shouldn't.

rdmark · 2023-10-21T08:49:24Z

I have yet to be able to reproduce this, after playing around with symlinks...

mikaku · 2023-10-21T10:03:08Z

I just saw that my current version was netatalk-3.1.17-1.el7.x86_64, so now I've upgrade it to netatalk-3.1.18-1.el7.x86_64.

I'll confirm you in the next days if I still see those messages in the log.

mikaku · 2023-10-27T17:11:32Z

Today appeared the following message repeated a lot of times, always with the same file name:

Oct 27 14:58:11 linux afpd[32451]: parse_entries: bogus eid: 9, off: 50, len: 3760
Oct 27 14:58:11 linux afpd[32451]: ad_header_read(/u/applepublic/xxx/231536/._Prop_2.ai): malformed AppleDouble
Oct 27 14:58:11 linux afpd[32451]: ad_header_read_osx(rfpath, ad, &st) failed: Input/output error
Oct 27 14:58:11 linux afpd[32451]: afp_openfork(Prop_2.ai): ad_open: Input/output error

I'll continue checking if the message appears with different file names.

rdmark · 2023-10-28T01:22:56Z

Curious, so the faulty metadata seems to originate with an Adobe Illustrator file. What happens it you save a new Illustrator file from within Illustrator directly onto the shared AFP volume? Also, please share the contents of your afp.conf file!

…

On Sat, Oct 28, 2023 at 2:11 AM, Jordi Sanfeliu ***@***.***(mailto:On Sat, Oct 28, 2023 at 2:11 AM, Jordi Sanfeliu <<a href=)> wrote: Today appeared the following message repeated a lot of times, always with the same file name: Oct 27 14:58:11 linux afpd[32451]: parse_entries: bogus eid: 9, off: 50, len: 3760 Oct 27 14:58:11 linux afpd[32451]: ad_header_read(/u/applepublic/xxx/231536/._Prop_2.ai): malformed AppleDouble Oct 27 14:58:11 linux afpd[32451]: ad_header_read_osx(rfpath, ad, &st) failed: Input/output error Oct 27 14:58:11 linux afpd[32451]: afp_openfork(Prop_2.ai): ad_open: Input/output error I'll continue checking if the message appears with different file names. — Reply to this email directly, [view it on GitHub](#270 (comment)), or [unsubscribe](https://github.com/notifications/unsubscribe-auth/AAQCYM6EFVEZZLBLT5PEHZ3YBPTM5AVCNFSM6AAAAAAWTUNWRWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTOOBTGI2DMNJZHE). You are receiving this because you were assigned.Message ID: ***@***.***>

mikaku · 2023-10-28T10:16:08Z

What happens it you save a new Illustrator file from within Illustrator directly onto the shared AFP volume?

I don't know, I can't give you an answer now. I need to talk with people from the design department Monday.

Also, please share the contents of your afp.conf file!

# cat /etc/netatalk/afp.conf
;
; Netatalk 3.x configuration file
;

[Global]
; Global server settings
hostname = linux
;uam list = uams_guest.so
uam list = uams_dhx2.so
login message = Welcome ...
afp interfaces = eno2

; [Homes]
; basedir regex = /home

[Linux Apple FAS5]
path = /u/applefas5

[Linux Apple Public]
path = /u/applepublic

slowfranklin · 2023-10-28T10:19:29Z

On 10/27/23 19:11, Jordi Sanfeliu wrote: ad_header_read_osx(rfpath, ad, &st) failed: Input/output error Oct 27 14:58:11 linux afpd[32451]: afp_openfork(Prop_2.ai): ad_open: Input/output error |

can you please attach the AppleDouble file so we can take a look? Thanks!

mikaku · 2023-10-28T10:36:56Z

can you please attach the AppleDouble file so we can take a look?

_Prop_2.ai.gz

slowfranklin · 2023-10-28T14:02:39Z

I guess the following patch should fix it. Can anyone test it?
look.patch.txt

mikaku · 2023-10-28T16:46:09Z

If you give me an RPM for a CentOS 7, I will install it and test it.

knight-of-ni · 2023-10-28T17:28:11Z

@mikaku I created a test build on Copr:
https://copr.fedorainfracloud.org/coprs/kni/netatalk/

mikaku · 2023-10-28T17:52:10Z

OK, I have now installed this one: netatalk-3.1.18-2.el7.x86_64.rpm.

Let's see how it works.
I'll be back with more news in the next days.

Thanks!

rdmark · 2023-11-04T23:16:17Z

@mikaku Were you able to test this yet?

mikaku · 2023-11-05T06:44:25Z

@rdmark, yes, no new messages appeared so far after installing the 3.1.18-2 version.

I'd like to wait a little more time because that past week there was some holidays and the company was not full of workers.

So, if you don't mind let's wait a week more.

rdmark · 2023-11-05T11:11:15Z

No rush at all! Please take a week to gather more data. It's encouraging that you haven't seen any issues so far.

FYI we're working towards a 3.2.0 release, which is at least several weeks out.

mikaku · 2023-11-10T08:42:19Z

@rdmark, So far I don't see any new message of type 'malformed AppleDouble' yet, but today I found 5 new messages like the following one:

Nov 10 07:55:22 linux afpd[4734]: ad_valid_header_osx("/u/applepublic/Dep.Disseny/Mar/xxx/27:10/A0811D000150741/._TA0811D000150741.jpg"): not an adouble:osx file

Are those messages somehow related to the changes made in 3.1.18-2 version?

rdmark · 2023-11-19T00:40:53Z

@mikaku Would you be able to share the ._TA0811D000150741.jpg meta data file (or any other that is being reported) here?

Also, are you seeing multiple warnings for the exact same file? I wonder if it gets converted to a compatible format later on.

It is likely that the patch above is related, because we are now better at trying to parse macOS appledouble meta data, and don't error out like before.

The question is whether the validation in ad_valid_header_osx() is correct and up to date with macOS standards or not (conversely, whether the meta data for that jpg file is valid or not.)

mikaku · 2023-11-19T07:16:34Z

Sorry, here is the file:

Also, are you seeing multiple warnings for the exact same file? I wonder if it gets converted to a compatible format later on.

Yes, that was in the beginning. During this week I saw similar messages for other files names.

Also I've seen a message that I think didn't see before: afpd[19099]: Convert OS X to Netatalk AppleDouble: <filename>. This message looks just informative though.

Let me know if you need more information.

rdmark · 2023-11-19T09:03:16Z

Thanks! And yes, that last message is what might indicate that the osx appledouble metadata is being converted to netatalk format.

This is what's in the file you shared:

mikaku · 2023-12-03T13:54:17Z

Hi, just an update.

I've not seen any new message of the type ad_valid_header_osx since 10 November, and only 7 messages have appeared in the logs of the type Convert OS X to Netatalk AppleDouble since then.

rdmark · 2023-12-03T23:14:16Z

@mikaku Thanks for the update. Given the evidence, my hypothesis is that outdated osx style meta data created by the older version of netatalk have all been converted now.

Is it fair to say that users of this AFP server were actively using it, creating files etc? Hopefully this would mean that macOS hasn't been creating meta data that netatalk couldn't parse.

Anyhow, I put up a PR now with Ralph's patch. #575

mikaku · 2023-12-04T10:02:09Z

@rdmark,

my hypothesis is that outdated osx style meta data created by the older version of netatalk have all been converted now.

Yep, I also think so.

Is it fair to say that users of this AFP server were actively using it, creating files etc?

Absolutely. I've just talked with some macOS users who write or create files in this AFP server and they have confirmed that they put new files, or modify existing ones in a daily basis. So it looks like good news.

slowfranklin · 2023-12-04T10:15:22Z

@mikaku Thanks for the update. Given the evidence, my hypothesis is that outdated osx style meta data created by the older version of netatalk have all been converted now.

fwiw, this files were NOT created by Netatalk. These are files created by macOS itself when working on filesystems that don't support macOS metadata natively, like SMB without streams support.

rdmark · 2023-12-08T01:43:19Z

The patch has been merged to the main development branch. Please file a new issue ticket if you run into other suspicious logs in the future!

mikaku mentioned this issue Apr 5, 2023

Netatalk 3.1.13 segfaults in afpd #175

Closed

mikaku closed this as completed May 10, 2023

rdmark reopened this Aug 10, 2023

rdmark self-assigned this Aug 10, 2023

rdmark added the target-release-3.1 label Aug 10, 2023

rdmark mentioned this issue Aug 11, 2023

Empty EA metadata leads to assert in ad_header_read_ea() #368

Closed

rdmark removed their assignment Oct 6, 2023

rdmark removed the target-release-3.1 label Oct 21, 2023

rdmark closed this as completed Dec 8, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"malformed AppleDouble" and "Input/output error" messages on 3.1.14 #270

"malformed AppleDouble" and "Input/output error" messages on 3.1.14 #270

mikaku commented Apr 5, 2023 •

edited

mikaku commented Apr 5, 2023

rdmark commented Apr 8, 2023

mikaku commented Apr 12, 2023

rdmark commented Apr 21, 2023 •

edited

mikaku commented Apr 27, 2023

rdmark commented Apr 27, 2023

mikaku commented Apr 29, 2023 •

edited

mikaku commented May 10, 2023

rdmark commented Aug 10, 2023

rdmark commented Oct 21, 2023

mikaku commented Oct 21, 2023

mikaku commented Oct 27, 2023

rdmark commented Oct 28, 2023 via email

mikaku commented Oct 28, 2023

slowfranklin commented Oct 28, 2023 via email

mikaku commented Oct 28, 2023

slowfranklin commented Oct 28, 2023

mikaku commented Oct 28, 2023

knight-of-ni commented Oct 28, 2023

mikaku commented Oct 28, 2023

rdmark commented Nov 4, 2023

mikaku commented Nov 5, 2023 •

edited

rdmark commented Nov 5, 2023 •

edited

mikaku commented Nov 10, 2023

rdmark commented Nov 19, 2023

mikaku commented Nov 19, 2023

rdmark commented Nov 19, 2023

mikaku commented Dec 3, 2023 •

edited

rdmark commented Dec 3, 2023

mikaku commented Dec 4, 2023 •

edited

slowfranklin commented Dec 4, 2023

rdmark commented Dec 8, 2023

"malformed AppleDouble" and "Input/output error" messages on 3.1.14 #270

"malformed AppleDouble" and "Input/output error" messages on 3.1.14 #270

Comments

mikaku commented Apr 5, 2023 • edited

mikaku commented Apr 5, 2023

rdmark commented Apr 8, 2023

mikaku commented Apr 12, 2023

rdmark commented Apr 21, 2023 • edited

mikaku commented Apr 27, 2023

rdmark commented Apr 27, 2023

mikaku commented Apr 29, 2023 • edited

mikaku commented May 10, 2023

rdmark commented Aug 10, 2023

rdmark commented Oct 21, 2023

mikaku commented Oct 21, 2023

mikaku commented Oct 27, 2023

rdmark commented Oct 28, 2023 via email

mikaku commented Oct 28, 2023

slowfranklin commented Oct 28, 2023 via email

mikaku commented Oct 28, 2023

slowfranklin commented Oct 28, 2023

mikaku commented Oct 28, 2023

knight-of-ni commented Oct 28, 2023

mikaku commented Oct 28, 2023

rdmark commented Nov 4, 2023

mikaku commented Nov 5, 2023 • edited

rdmark commented Nov 5, 2023 • edited

mikaku commented Nov 10, 2023

rdmark commented Nov 19, 2023

mikaku commented Nov 19, 2023

rdmark commented Nov 19, 2023

mikaku commented Dec 3, 2023 • edited

rdmark commented Dec 3, 2023

mikaku commented Dec 4, 2023 • edited

slowfranklin commented Dec 4, 2023

rdmark commented Dec 8, 2023

mikaku commented Apr 5, 2023 •

edited

rdmark commented Apr 21, 2023 •

edited

mikaku commented Apr 29, 2023 •

edited

mikaku commented Nov 5, 2023 •

edited

rdmark commented Nov 5, 2023 •

edited

mikaku commented Dec 3, 2023 •

edited

mikaku commented Dec 4, 2023 •

edited