Uploads of files inside subdirectories always initially fail with a "Tahoe API error 500"

[crwood]

When using/testing the latest Magic-Folder (main@HEAD, rev b9b7864735d7742b3e3a8e16c94617736883bc3a), I noticed that, if I add a new magic-folder that contains subdirectories containing files, uploads for those files-inside-subdirectories will always throw a "Tahoe API error 500" on the (first?) upload attempt (whereas files that are not inside subdirectories do not). Perhaps this is somehow related to #571? In any case, here's an example websocket/status message from where I observe the error:

{
    "state": {
        "folders": {
            "Cat Pics": {
                "downloads": [],
                "errors": [     
                    {      
                        "timestamp": 1635343168,
                        "summary": "Error uploading subdir/lolcat.jpg: Tahoe API error 500",
                    },                                                                      
                    { 
                        "timestamp": 1635343168,
                        "summary": "Error uploading subdir/Garfield.jpg: Tahoe API error 500",
                    },                                                                        
                ],    
                "uploads": [],
                "recent": [   
                    {      
                        "conflicted": false,
                        "modified": 1635343128,
                        "last-updated": 1635343171,
                        "relpath": "subdir/Garfield.jpg",
                    },                                   
                    { 
                        "conflicted": false,
                        "modified": 1635342408,
                        "last-updated": 1635343171,
                        "relpath": "subdir/lolcat.jpg",
                    },                                 
                    { 
                        "conflicted": false,
                        "modified": 1634226039,
                        "last-updated": 1635343170,
                        "relpath": "lolcat.jpg",   
                    },                          
                    { 
                        "conflicted": false,
                        "modified": 1634410734,
                        "last-updated": 1635343170,
                        "relpath": "Garfield.jpg", 
                    },                            
                ],    
            }     
        },   
        "synchronizing": false,
    }                          
}    

Judging by the timestamps in recent, it looks like the uploads do succeed a few seconds later so I'm wondering now whether the conditions that caused the initial 500 could/should be addressed so that the error isn't thrown in the first place; it probably(?) doesn't add much value to propagate or persist errors in status messages for errors can -- and, in this case, are -- immediately and automatically resolved without user interaction.

[meejah]

Is this repeatable, or just happened once? (I can't repeat with pre-existing subdirectories in a newly created magic-folder nor by copying in a tree of files to an existing folder).

Also if you have the eliot logs from this failure, can you please attach them to this ticket?

[meejah]

(I don't believe it is related to the download thing .. upon upload, whether the file is in a subdir or not shouldn't be very relevant -- except that the encoded snapshot relpath is a bit different / longer).

[meejah]

I tried some manual tests and can't repeat -- can you confirm this always happens for you?

[crwood]

I am still able to reproduce the same error -- with the same folder on two separate grids (the Tahoe-LAFS "pubgrid" and a personal/single node demo grid). I've attached below a zip archive of the "Cat Pics" test folder I'm using as well as eliot logs from both Tahoe-LAFS and Magic-Folder for each of the two instances I tried:

CatPics.zip
test-grid-tahoe-lafs-eliot.log
test-grid-magic-folder-eliot.log
demo-grid-tahoe-lafs-eliot.log
demo-grid-magic-folder-eliot.log

In each case, I see tahoe spewing allmydata.interfaces.UploadUnhappinessError (which probably coincides with the "Tahoe API error 500" messages?) but this seems unusual since, in both cases, I was connected to enough servers (as per the Tahoe-LAFS WebUI's "welcome page"). It's also unusual that only the files inside the subdirectories are throwing UploadUnhappinessError; this doesn't happen for folders inside the top level of the Magic-Folder directory.