rsync 3.2.7 client fails "rejecting unrequested file-list name" talking to rsync 3.2.7 (and ealier) server.

[JoshLitt]

Using rsync 3.2.7 client over SSH to copy files from a remote system, I have an issue where it fails with "rejecting unrequested file-list name". I first saw this with a 3.1.2. remote rsync server, but find it happens just as much with a 3.2.7 server. Of course, this works with --trust-sender, but I can't use that option in our application.

Unfortunately the context for this is not simple. We see this using the Vertica (www.vertica.com) vbr.py script for database restore. This script runs multiple worker processes on multiple nodes, all working simultaneously. I've reproduced it in a more limited case with 1 worker process running the rsync client on 1 node. The repro is the last of a series of transfers with sequential rsync invocations. I can't repro it in a single rsync command.

Generally, after learning about the remote files, the client does a series of file retrievals as:

rsync -s --whole-file --size-only --from0 --files-from=- <remote-host>:<remote-path> <local-path>

It uses RSYNC_RSH set to ssh -T -x -o PasswordAuthentication=no -o StrictHostKeyChecking=no -o NoHostAuthenticationForLocalhost=yes

This is driven by python, and the file list sent to stdin is from (python) '\0'.join(file_list). An example failure came from this list:

['647/02ebe16bb99a537f76d75c4deebaf89900c00000000ff8a7_0.gt', '649/02ebe16bb99a537f76d75c4deebaf89900c00000000ff8a9_0.gt', '651/02ebe16bb99a537f76d75c4deebaf89900c00000000ff8ab_0.gt',
 '697/02ebe16bb99a537f76d75c4deebaf89900c00000000ff8d9_0.gt', '541/02ebe16bb99a537f76d75c4deebaf89900c00000000ffc25_0.gt', '717/02ebe16bb99a537f76d75c4deebaf89900c0000000103385_0.gt',
 '721/02ebe16bb99a537f76d75c4deebaf89900c0000000103389_0.gt', '723/02ebe16bb99a537f76d75c4deebaf89900c000000010338b_0.gt', '725/02ebe16bb99a537f76d75c4deebaf89900c000000010338d_0.gt',
 '737/02ebe16bb99a537f76d75c4deebaf89900c0000000103399_0.gt', '739/02ebe16bb99a537f76d75c4deebaf89900c000000010339b_0.gt', '741/02ebe16bb99a537f76d75c4deebaf89900c000000010339d_0.gt',
 '743/02ebe16bb99a537f76d75c4deebaf89900c000000010339f_0.gt', '747/02ebe16bb99a537f76d75c4deebaf89900c00000001033a3_0.gt', '749/02ebe16bb99a537f76d75c4deebaf89900c00000001033a5_0.gt',
 '751/02ebe16bb99a537f76d75c4deebaf89900c00000001033a7_0.gt', '753/02ebe16bb99a537f76d75c4deebaf89900c00000001033a9_0.gt', '755/02ebe16bb99a537f76d75c4deebaf89900c00000001033ab_0.gt',
 '757/02ebe16bb99a537f76d75c4deebaf89900c00000001033ad_0.gt', '765/02ebe16bb99a537f76d75c4deebaf89900c00000001033b5_0.gt', '767/02ebe16bb99a537f76d75c4deebaf89900c00000001033b7_0.gt',
 '769/02ebe16bb99a537f76d75c4deebaf89900c00000001033b9_0.gt', '771/02ebe16bb99a537f76d75c4deebaf89900c00000001033bb_0.gt', '773/02ebe16bb99a537f76d75c4deebaf89900c00000001033bd_0.gt',
 '785/02ebe16bb99a537f76d75c4deebaf89900c00000001033c9_0.gt', '787/02ebe16bb99a537f76d75c4deebaf89900c00000001033cb_0.gt', '789/02ebe16bb99a537f76d75c4deebaf89900c00000001033cd_0.gt',
 '791/02ebe16bb99a537f76d75c4deebaf89900c00000001033cf_0.gt', '793/02ebe16bb99a537f76d75c4deebaf89900c00000001033d1_0.gt', '809/02ebe16bb99a537f76d75c4deebaf89900c00000001033e1_0.gt',
 '811/02ebe16bb99a537f76d75c4deebaf89900c00000001033e3_0.gt', '813/02ebe16bb99a537f76d75c4deebaf89900c00000001033e5_0.gt', '815/02ebe16bb99a537f76d75c4deebaf89900c00000001033e7_0.gt',
 '817/02ebe16bb99a537f76d75c4deebaf89900c00000001033e9_0.gt', '827/02ebe16bb99a537f76d75c4deebaf89900c00000001033f3_0.gt', '867/02ebe16bb99a537f76d75c4deebaf89900c000000010341b_0.gt']

The error was ERROR: rejecting unrequested file-list name: 867. In all cases, the error complains about a directory name, and it's always the directory name of the LAST file in the list. But this is after many similar requests are successful. Depending on the state of the systems, it happen on different names. For example, it may successfully copy 4% of the data before it happens. Retrying, which will copy missing data may fail on a different name much later, after 41% is copied. A third try may succeed.

In the simplest case I've got currently, it fails on the 14th file-set retrieval.

I put that same file list into a null-separated file and ran the same command, after wiping out local files/directories, to try to repro, and it works OK. So I can't describe a simple case to reproduce this.

Are there options that would help identify the issue?

I've tried adding -vvv --log-file=X --remote-options=--log-file=Y. I've attached the client and server logs (note: one is UTC and one is EDT, so the times are 4 hrs apart). There are a series of rsync instances involved on both sides, indicated by the changing PIDs. The failing server pid (last in the log) is 43285 and this is also referenced in the client log. The file list in the failing transfer is the same as above.
rsync-issue-client.log
rsync-issue-server.log

I do wonder if rather than aborting on an unrequested file name, it could just be logged and ignored (maybe as an option). That would seem to retain the protection from CVE-2022-29154, without resorting to --trust-sender.

[carenas]

This is driven by python, and the file list sent to stdin is from (python) '\0'.join(file_list)

assuming this line comes from vbr.py, wouldn't the generated list of files to transfer be incomplete and missing the trailing NUL?, does using '\0'.join(file_list)+'\0' instead make a difference?

[JoshLitt]

@carenas I will try adding a trailing null. Looking at the file I used for the test I mentioned of putting that file list in a null-separated file and running command, I see that actually did have a trailing null (can't recall, but I think I generated it with sed replacing newlines with null, and it had a trailing newline.)

[JoshLitt]

Well, that was it. But whether or not it fails as it did may have to do with internal buffer mgmt boundaries. If I put the above file list in a null-separated list with a terminating null, it works. Without the terminating null, it fails. Changing the vbr.py script as you suggested ensures it too works. Yet if I use a list of 2 filenames, it works regardless of the terminating null.
I checked the rsync code to see where this sensitivity might be, and it wasn't obvious.

However, now that I understand this is often used in combination with find ... -print0, it makes sense to have a trailing null. The null isn't a field delimiter as much as terminator, though the man page uses both words for this in different places. That said, one could also expect that this case (no final NULL) should work. For example, xargs -0 seems to have no issue with this.