I realize this will cause logs to become more noisy and i'm not sure if we really can guarantee the result without slowing rclone down but I ran into a logging issue today.
I made a mistake and began deleting some files (no, a confirmation dialog wouldn't have helped. ) . I was running a DEBUG and producing a logfile. I immediately saw my error and hit ctrl-c. I then went into my logfile, identified what happened and restored from google trash the one file it showed as deleted. That log, however, was not complete since it writes to the log after the activity is complete and i hit 'ctrl-c'. I was running with a large number of transfers so there could have been a large number of outstanding 'deletes' that weren't captured. In my case it was only 6. I was able to determine the missing files by comparing to my backup to see what damage was done. I then confirmed it in google drive with the delete date activity information.
Do we think it is worthwhile to have the log written to before threads delete the files or for that matter before any 'activity'. It would have made it just a bit easier to know what had happened. Someone without a backup and with a massive amount of files in the trash might not have known about the other files.
Just a thought. In my case I have backups but I might have walked away after restoring just that one file (and lost 5 others).
I really hate to make the logs even more verbose. But figured i'd pose the question.
If nothing else, we just acknowledge it as an issue.
Yes you are right rclone normally logs after the action is complete which is generally what you want in a log, eg XXXX is deleted. In some places rclone says "XXX: about to YYY" as a DEBUG message.
Rclone logs at INFO level when it deletes stuff so we could have a pre-delete DEBUG log. As you said though that does make things a bit noisy so I'm not wildly keen on the idea.
I note in your particular case could you have ordered the files by trashed date to see which ones were trashed recently?
According to the API there is a "trashedTime": datetime parameter. Rclone doesn't surface this at the moment though... I looked through the advanced search options for drive and it doesn't seem to allow you to use that.
This isn't a big deal. I was prepared for this sort of thing. I was just thinking I'd share the issue to make it known that the log might not have all the entries. I, same as you, hesitate to make the logs more verbose than they already are though.
) . I was running a DEBUG and producing a logfile. I immediately saw my error and hit ctrl-c. I then went into my logfile, identified what happened and restored from google trash the one file it showed as deleted. That log, however, was not complete since it writes to the log after the activity is complete and i hit 'ctrl-c'. I was running with a large number of transfers so there could have been a large number of outstanding 'deletes' that weren't captured. In my case it was only 6. I was able to determine the missing files by comparing to my backup to see what damage was done. I then confirmed it in google drive with the delete date activity information.
