Bug of the moment 2007-07-18
I run a relatively archaic version of the BulletProof FTP server, so this is not a knock on the application itself since I imagine this is long since fixed. I just found the bug so bizarre that I felt it definitely worth a mention.
Take a look at this output from the log window of the FTP server: do you notice anything odd about it?
… (…) > logged in.
… (…) > asked to upload 'comedyfalle_bymk.wmv' in 'C:\…\' --> Access allowed.
… (…) > started uploading 'comedyfalle_bymk.wmv' in 'C:\…\'.
… (…) > finished uploading 'comedyfalle_bymk.wmv' in 'C:\…\' - (00:01:21 - 4067.242 KB - 50.213 KBytes/s).
… (…) > asked to delete 'C:\…\comedyfalle_bymk.wmv' --> Access allowed.
… (…) > asked to upload 'container.wmv' in 'C:\…\' --> Access allowed.
… (…) > started uploading 'container.wmv' in 'C:\…\'.
… (…) > finished uploading 'container.wmv' in 'C:\…\' - (00:00:09 - 462.102 KB - 51.345 KBytes/s).
… (…) > asked to delete 'C:\…\container.wmv' --> Access allowed.
… (…) > asked to upload 'denverclan.avi' in 'C:\…\' --> Access allowed.
… (…) > started uploading 'denverclan.avi' in 'C:\…\'.
… (…) > finished uploading 'denverclan.avi' in 'C:\…\' - (00:08:19 - 21926.000 KB - 43.940 KBytes/s).
… (…) > asked to delete 'C:\…\denverclan.avi' --> Access allowed.
A while ago, Ian Bell uploaded me a file to my server (a sneaky preview of Fragmentary Glimpses of Eternity 4 track 1), and as soon as the transfer was complete, his client requested the file be deleted. I felt this to be rather odd, but he had no explanation for it. It was not a one-off occurrence: I would repeatedly see the server log report attempted deletions of freshly-uploaded files by other users.
Generally, it was of no consequence, because I was not permitting delete on any user accounts shared by more than one person, or with the public. FTP through NAT, especially behind my BEFSR41 router, is especially troublesome, so I wrote off the phenomenon as NAT-induced insanity.
It was this insanity that led me to grant one account – the one shown above – more open permissions. One user was seeing so much connection failure that I decided that I could trust everyone to behave, and opened up the account so delete and append would be permitted. Which brings me back to the log above, of uploads from someone else who has no connection trouble. Notice the deletion requests immediately after upload completion? They’re being granted, yet, when I checked, the files weren’t going anywhere. Delete requests that were not deleting anything.
I smelt a rat at this point, and decided to check the comprehensive on-disc log to see what really happened. This is what I saw:
… (…) > STOR denverclan.avi
… (…) > asked to upload 'denverclan.avi' in 'C:\…\' --> Access allowed.
… (…) > 150 Data connection accepted from …:33130; transfer starting for denverclan.avi.
… (…) > started uploading 'denverclan.avi' in 'C:\…\'.
… (…) > 226 File received ok.
… (…) > finished uploading 'denverclan.avi' in 'C:\…\' - (00:08:19 - 21926.000 KB - 43.940 KBytes/s).
… (…) > MDTM 20051101031206 denverclan.avi
… (…) > asked to delete 'C:\…\denverclan.avi' --> Access allowed.
… (…) > 253 Date/time changed
Obligatory screenshot – what is Audacity’s playback state in the following picture?
Posted 18th July 2007 – Comments and questions?