Pythonでのフォルダ監視（watchdog）： ファイル移動が達成されているが、元フォルダにファイルが残っていることがある！

Question

クラウドのシステム向けに　社内データを送信する運用環境が整っています。
.txtでのファイルを送信し終えると、.csvのファイルが　同フォルダに提供されます。

この送信データであるTEXTファイルと処理結果のCSVファイルの自動退避、及び処理結果であるCSVファイルをメール送信しようと考え、経験浅いながらPythonで以下を作ってみました。（ネット記事切貼りとこちらでの支援により）

送信すべきTEXTファイルを、このプログラムで監視しようとするフォルダに配置した上、送信処理手前で起動しています。　
つまりは監視下にあるフォルダに　CSVファイルの新規発生が　メール送信・退避移動の発火にした作りです。　

from watchdog.events import FileSystemEventHandler
from watchdog.observers import Observer
import os
import time

from email.mime.text import MIMEText
from email.mime.application import MIMEApplication
from email.mime.multipart import MIMEMultipart
from email.mime.base import MIMEBase
from email.header import Header
from email import policy
from email import encoders
from os.path import basename
from email.utils import formatdate
import os
import sys
import smtplib

import datetime
import shutil

arges = sys.argv
argcnt = len(arges) -1   #０番目のコマンドライン引数は当該プログラムのパスになるため

class Email():
    def __init__(self):
        
        self.mlsrv = ""
        self.mlsrv_port = 587
        self.mlsrv_id = ""
        self.mlsrv_pw = ""
        self.mlsrv_fraddress = "@.com"


    def send_Mail(self, toaddress, ccaddress, bccaddress, subject, filepath):
        try:

			#メール送信の処理　割愛
			
        except Exception as e:
        
        
        finally:
            return result



class BackUp():
###############################################################################################
# 送信処理が終わると、処理結果がＣＳＶで　同フォルダに提供される⇒⇒⇒メール送信後に送信データと併せ退避
    
    # 監視フォルダと　退避先フォルダが引数
    def move_files(self, src_dir, dst_dir):

        dt_now = datetime.datetime.now()
        dst_dir = dst_dir + "/" + dt_now.strftime('%Y%m%d%H%M%S')
        os.makedirs(dst_dir, exist_ok=True)	#指定の退避先フォルダ内に日付時間フォルダを作成
        
        for p in os.listdir(src_dir):		#監視フォルダ内コレクションループ
            fullpath = os.path.join(src_dir, p)	#ファイルのフルパスを取得
            
            wcnt = 0				#この関数動作由来の新規ファイルはサイズ０の可能性あり-->待機
            while True:
                size = os.path.getsize(fullpath)
                if size == 0 :
                    wcnt += 1
                    if wcnt > 1800 :	#無限ループ対策（30）
                        break
                    time.sleep(3)
                else :
                    break

            base, ext = os.path.splitext(p)
            if ext == ".csv" :			#サイズ１以上ＣＳＶファイルは処理結果内容-->メールで添付送信
                if argcnt < 5 :
                    if argcnt == 4 :
                        result = mail.send_Mail(引数の数から宛先のみの指定)
                    elif argcnt == 3 :
                        result = mail.send_Mail(引数の数から宛先・ＣＣのみの指定)
                else :
                    result = mail.send_Mail(引数の数から宛先・ＣＣ・ＢＣＣ全てを指定)
            
            wcnt = 0
            while True: 
                wcnt += 1
                if wcnt > 1800 :		#無限ループ対策（30）
                    break
                try :
                    shutil.move(os.path.join(src_dir, p), dst_dir)#★移動できれば使用中でないと判断★
                    break
                except Exception as e:
                    time.sleep(1)	#★移動できなければ送信中と判断、また移動をリトライ★


#★★★監視フォルダ内全てのファイルが移動退避し終えたら　関数を終わらせてアプリも閉じたい★★★

'''
######################################################################################################
#                                                                                                                                   #
#                                                                                                                                   #
#                                                                                                                                #
######################################################################################################
'''
class ChangeHandler(FileSystemEventHandler):
   def __init__(self, observer):
       self.observer = observer

   def on_created(self, event):

        if argcnt < 5 :
            if argcnt == 4 :
                backup.move_files(arges[3], arges[4]) 
            elif argcnt == 3 :
                backup.move_files(arges[2], arges[3])
        else :
            backup.move_files(arges[4], arges[5])
        

        self.observer.unschedule_all()#★★　監視フォルダに送信ファイル残ることがある。でも退避もされている！
        self.observer.stop()	#★★　しかも終わってくれない（新たな監視状況がつくりだされているような感じ）



if __name__ in '__main__':
    mail = Email()
    backup = BackUp()

    if argcnt < 5 :
        if argcnt == 4 :
            target_dir = arges[3]
        elif argcnt == 3 :
            target_dir = arges[2]
        elif argcnt <= 2 :
            print("引数不足、起動できません")
            sys.exit(9)
    else :
        target_dir = arges[4]

    
    observer = Observer()
    event_handler = ChangeHandler(observer)
    observer.schedule(event_handler, target_dir, recursive=True)#特定のフォルダを引数に与えて監視スタート
    observer.start()
    try:
       while observer.is_alive():
            time.sleep(0.1)
    except KeyboardInterrupt:
           observer.unschedule_all()
           observer.stop()
    observer.join()

質問

元フォルダにファイルが残ってしまっている状況が発生しています。データの種類によって、元フォルダがクリアされている・されていないの違いがあるようです。
しかし　退避先フォルダには　元フォルダへ残ってしまったファイルも必ず配置されていることが確認できています。

本来メール報告とファイル退避を終えたら　【当該アプリケーション自体】を終わらせることを望んでいますが、先の問題が生じるパターンでは　いつになっても終わらない問題も生じています。---->新たな監視状況が作られてしまっているような感じ？！　でしょうか．．．．．

これは　上記のコードで　一体何が悪く　このような問題が起きてしまっているのでしょうか？　どなたかご教示を頂けますと幸いです、よろしくお願い申し上げます。

追記20210307 10:10

ベンダ様から提供されているデータ送信処理のバットファイルに、自分のアプリが前もって起動されるよう挿入したのですが
データ種類の違いで　データ送信処理の実装方法が異なるようです。このことから監視フォルダに生成されるCSVファイルの生成・使用タイミング（共有状況）に違いを生んでいる可能性があります。以下バットファイルの【違い】を表しました。
フリーの監視ソフトによって　送信すべきデータファイルが所定フォルダに配置されると　以下のバットファイルが動作するようになっていますが、これが再度実施されていて　自分のアプリケーションも再起動されている可能性があります．．．．（でもフリーの監視ソフトにその記録が残っていない）

【問題ないパターン↓】

@ECHO OFF
rem #########################################################
rem # 
rem #########################################################

START D:\今回作ったプログラム 引数１, 引数２, 引数３

rem 送信処理、本来このコマンド行のみのバットファイルだが上記START文を追加

UPSERT.bat "ITEMMASTER_upsert"
```　　

【問題あるパターン↓】
```bat
@ECHO OFF
rem #########################################################
rem # 
rem #########################################################

START D:\今回作ったプログラム 引数１, 引数２, 引数３

rem 送信処理、本来このコマンド行のみのバットファイルだが上記START文を追加
DELETE_INSERT.bat "STOCKS_export" "STOCKS_delete" "STOCKS_insert"

追加報告 20200307 11:40

送信データが移動元フォルダに残ってしまう事象につき、また当該アプリケーションが動作し続けることから以下を試行
①フリーソフトの当該バットファイルの実装設定（検知設定）を前回実行から３分過ぎない限り再実施無理なよう対応。
=> 効果なし、フリーソフトのログに当初から２重実行されている記録は残っていないので納得の結果

②自アプリケーション内で　新規ファイル察知（１バイト以上）後の　メール・退避動作までの待機時間３分を挿入。
=>効果なし、相変わらず移動元フォルダに送信データ残るが　退避先フォルダには処理結果ＣＳＶと共に保管されている。

一体何が起きているのだと思い、移動元フォルダに残ったファイルを　コマンドプロンプトから削除を試行

アクセスが拒否されました、と言われながら　移動はできた....状況ですね。
ベンダ様提供のプログラムが　C#やVB.NETでいうUsingみたいなものを使っていない、というこでしょうか？
何か　当方のPython側で　どうにか対策できないでしょうか

20210307 14:35 qnoirさん提供プログラム、デバッグ実行の結果

20210305 15:35 qnoirさん提供プログラム実行結果

【１回目↓】

2021-03-07 15:21:11,822 |  Started to observe. [path : .\20210307_152111_6038_log.txt]
2021-03-07 15:21:35,150 |  on_created()  : C:\Tools\SalesforceConnect\data\SFA09\Reservation_insert_error.csv
2021-03-07 15:21:38,384 |  on_modified(): C:\Tools\SalesforceConnect\data\SFA09\Reservation_insert_error.csv
2021-03-07 15:21:46,792 |  on_modified(): C:\Tools\SalesforceConnect\data\SFA09\Reservation_insert_error.csv

【２回目↓】

2021-03-07 15:25:08,158 |  Started to observe. [path : .\20210307_152508_5250_log.txt]
2021-03-07 15:25:34,611 |  on_created()  : C:\Tools\SalesforceConnect\data\SFA09\Reservation_insert_error.csv
2021-03-07 15:25:38,299 |  on_modified(): C:\Tools\SalesforceConnect\data\SFA09\Reservation_insert_error.csv
2021-03-07 15:25:49,393 |  on_modified(): C:\Tools\SalesforceConnect\data\SFA09\Reservation_insert_error.csv

Comments

[退会済みユーザー]

念のため確認ですが、退避先（コピー先　dst_dir)は、監視元フォルダ（target_dir ＝ src_dir）の子フォルダではない、という理解でいいでしょうか？

（ observer.schedule(event_handler, target_dir, recursive=True)
で　recursive=True（再帰）となっているため、
仮にコピー先（退避先）がtarget_dirの子フォルダの場合、コピーすることによってon_createdイベントが追加で発生する気がするため）

[saya24]

qnoirさん　ご質問の件、退避先のフォルダは　監視先のフォルダと　ドライブさえも異なります。

でもon createdイベントが余計に走ってしまっている雰囲気は同感です。

明日実行パラメータの部分を再度確認してみます

[saya24]

フリーのフォルダ監視ソフトと、自分のアプリケーション（watchdog）でも　同じ対象フォルダが監視されていることに起因しているのだろうか？？？
フリーのフォルダ監視ソフトは　別サーバから送信すべきファイルが置かれるので、送信処理発火用。
自アプリケーションは　送信処理が終わったことに由来し対応する作業を　自動化するためのもの。

はぁ困ったわ

Answer 1

本質的な解決に関する回答ではなりませんが、二重起動の要因について

・フリーの監視ソフトが二重起動している可能性　（質問文の内容から、監視ソフトのログを見る限りではその可能性はなさそう、と理解しました）
・watchlogが同じファイルの作成を二重検知している可能性
・ファイル送信csvは一度しか配置されないはずだが、内部で別の隠しファイルが一時的に作成され、それを検知している可能性

まず上記の切り分けのために、下記コードを、CSVメール・ファイル退避用コードの代わりに起動するようにバッチファイルに記述していただけないでしょうか。

単純に、下のコードの起動以降の、監視対象フォルダ内のファイルの動きを、ログファイルとして表示・記録するものです。

ずっと動き続けるので停止する場合はCtrl+C等で止めてください。

（下記コードを実行すると、下記コードを保存したフォルダにログファイルが作成されます。
ログの保存フォルダを変える場合はlogfiledirを書き換えてください。）

これをテスト実行した結果のシナリオとして下記が考えられます。

１．ログファイルは１回しか作成されない－＞フリーの監視ソフトは二重起動していない、ということになる。
仮にログファイルに、watchdog側で、把握していなかった別のファイルが密かに作成され、削除されていることが記録されていた場合
→本番処理では、当該ファイルが作成されてもファイルのコピー退避処理を行わないようにすることで対応
（あくまで、送信完了のcsvが作成されたときに限定して退避処理を行うようにする。
どのファイルが作成されたかは、on_created(self, event)関数内で、event.src_pathを使えば取得できます。）



２．ログファイルが２回作成される－＞ファイル配置時にフリーの監視ソフトが二重起動している可能性があります。
（下記コードでは作成時刻をログファイル名にするようにしているため、フリーの監視ソフトが二重起動し下記watchdogのコードも２回起動したならば、ログファイルは２つ作成されてしまうはずです）

この場合、フリーの監視ソフトを一旦停止（終了）し、フリーの監視ソフトの代わりに下記コードをあらかじめ実行して改めてログをとってみてください。
フリーの監視ソフトが二重起動していた理由がわかるかもしれません。
(フリーの監視ソフトのログで記録できていなかったものが、下記のコードで記録できるかどうかは不明ですが・・・)

import logging
import os
import datetime
import time
import random
from watchdog.events import FileSystemEventHandler
from watchdog.observers import Observer

folder_path = "監視対象のフォルダ"

logfiledir = "."
sn = str.zfill(str(random.randint(0,10000)),4)
logfilename = datetime.datetime.now().strftime('%Y%m%d_%H%M%S_'+sn) + "_log.txt"

logfilepath = os.path.join(logfiledir, logfilename)
logger = logging.getLogger(__name__) 
logger.setLevel(logging.DEBUG)

handler1 = logging.StreamHandler()
handler1.setFormatter(logging.Formatter("%(asctime)s |  %(message)s"))

handler2 = logging.FileHandler(filename=logfilepath, encoding='utf-8')
handler2.setLevel(logging.DEBUG)
handler2.setFormatter(logging.Formatter("%(asctime)s |  %(message)s"))

logger.addHandler(handler1)
logger.addHandler(handler2)


class ChangeHandler(FileSystemEventHandler):

    def __init__(self):
        super().__init__()
        
    def on_created(self, event):
        if event.src_path != logfilepath:
            logger.debug('on_created()  : %s'%(event.src_path))

    def on_modified(self, event):
        if event.src_path != logfilepath:
            logger.debug(f"on_modified(): {event.src_path}")

    def on_moved(self, event):
        logger.debug('on_moved()    : %s ' % event.src_path)

    def on_deleted(self, event):
        logger.debug('on_deleted()  : %s ' % event.src_path)

event_handler = ChangeHandler()
observer = Observer()

observer.schedule(event_handler, folder_path, recursive=False)

observer.start()
logger.debug(f"Started to observe. [path : {logfilepath}]")
print()
try:
    while observer.is_alive():
        time.sleep(1)
except KeyboardInterrupt:
    pass

observer.stop()
observer.join()
logger.debug('Script quit.')

Comments

[saya24]

qnoirさん、大変親切なご対応を誠にありがとうございます。今回自分が作成したアプリの代替え版として、今からやってみます。
target-dirの変数に　監視フォルダを直書きしたうえで　ですね。少々お待ちをくださいませ。

不慣れで時間要してしまうかもですが

[saya24]

本文に今から　貼り付けますが　ご提供のプログラムがSyntaxエラーを招くようです。
一度運用環境で試してFatalErrorになったので　試しにVisualStudioでのデバッグ実行を確認したところ　本文に貼り付けた　エラーを招きました。
今から画像貼り付けます、すみません....。

[saya24]

import random を入れればよいですかね

[退会済みユーザー]

すみません。修正しました。

[saya24]

いえ、とんでもないです。実は　また別のSyntaxエラーが生じております。
これは　さすがに見当がつきません....

Message='locale' codec can't encode character '\u5e74' in position 2: Illegal byte sequence
Source=C:\Users\xxxxx\source\repos\QNOIR\QNOIR\QNOIR.py
スタック トレース:
File "C:\Users\xxxxx\source\repos\QNOIR\QNOIR\QNOIR.py", line 15, in <module>
logfilename = datetime.datetime.now().strftime('%Y年%m月%d日%H時%M分%S秒'+sn) + "_log.txt"

[退会済みユーザー]

strftimeのパターンに日本語が含まれていたため発生したエラーのようです。
検索するとlocale をインポートしてコード追加すれば対応することができるとの記述もありましたが
それでもエラーが出る場合があるとのことで。
念のため一旦コードから日本語を全部除去しました。お手数ですがこれで試していただけますでしょうか。

[saya24]

本当にご親切に至れり尽くせり　ありがとうございます、
無事にご提示のプログラム動作しまして、ログの採取が行えました。
２回試しました結果を　いまから本文に貼り付けますね。

尚、自動では停止しなかったので　タスクマネージャから停止させて頂きました

[saya24]

Reservation_insert_error.csvとは　メールに添付されるべき処理結果ファイルで　この存在の察知からメール配信と　当該ファイルおよび送信データであるテキストファイルの退避を　予定しています。

余計なファイルは　生成されていない、という結果ですかねぇ

[退会済みユーザー]

結果の貼り付けありがとうございます。
結果を見る限りではwatchdog側でも二重起動はしていない（on_createdは２回呼ばれておらず、Reservation_insert_error.csv以外の余計なファイルも特に作られている気配はない）ということのようですね・・・
（on_modifiedが数秒あけて発生していることから、通知ファイルについては最初に空のファイルが作られて、後から10秒～20秒かけて内容が追記されていく、ということのようですね）

あと、コピー／移動のところ、前回の質問のコメントで「もし退避対象のファイルがクラウドへ送信中ならばshutilsでmoveさせようとした時点で例外が発生するはず」と申し上げましたが、これも誤りだったようです（実際には、送信中ファイルに対しshutil.move()をかけても例外は発生せず、コピー扱いになる）。申し訳ございません。

「１つ１つのファイルがクラウドへ送信中かどうか」が分からないと、スマートな手段での解決は難しそうですね。

あとは、
・Reservation_insert_error.csvファイルが届いたことを検知した後、2分待ってReservation_insert_error.csvファイルをメール添付（届いてから2分も経過すればReservation_insert_error.csvは完成しているはずとの前提）
・フォルダへの退避は、移動ではなく、shutillを使ってコピーするだけにして、コピー時に削除対象ファイルのパスを別ファイルに記録しておき、削除処理は、別プログラムで半日後／もしくは一日後に記録を参照して一気に行う。
といったやり方しかなさそうです。

（「何時間たてば確実にaccess_deniedが発生しなくなるか」というのがわかればその時間まで短縮できると思いますが）

本件でwatchdogが終了できない、という原因も今のところ分かりませんでした（それこそexit(0）で終了させるしかないかも）
お役に立てずすみません。

[saya24]

>「１つ１つのファイルがクラウドへ送信中かどうか」が分からないと、

データ種類ごとにバットファイルが分かれています。今、問題がおきている部類のデータ種類はクラウド側の同データを　クリアしたのち投入する部類で　全入れ替えが行われる部類です。
うまくいくデータ種類（期待の動作を達成するバットファイル）は　社内で変化のあったデータのみを渡す部類で、クラウド側で更新されるべきデータのみを送っている部類です。

やはり　まだCSVファイルが書き込みされている段階で　異動されていることが　当該送信データが残る・当該アプリが閉じない　ことの問題の本質となると　ファイル名のリネームの試行というのは　どうですかね？？？

現段階では　自分のアプリケーションが終わらなくなってしまっていることが　一番片づけたい課題です。

[saya24]

qnorさん　色々とありがとうございました、心の底より　本当に感謝を申し上げます。

処理結果のCSVファイルのリネームが成功したかしないかで、処理がおえたか否かを判断するようにして（現実終わっているのに送信データのアクセス権が解放されないデータ種類がある解釈）、処理を終えたと判断できたら　従来どおり　メールと退避フォルダへの移動を行うようにしてアプリケーションを終わらせるようにしました。

テキストファイルである送信データが移動できたとしても　フォルダに残りっぱなしだと、フォルダ内のコレクション（For文）が永遠にループして　アプリがいつまでも閉じなかっただけなんですね....。

現況ですが　退避フォルダに処理結果CSVと送信データテキストが無事保管され、アプリも無事に終わるようになった、しかし元フォルダに送信データテキストが残ってしまうデータ種類がある、という状況です。
Pythonで管理者権限でファイル削除って　できますか？？
はっきりいって送信処理は完全に終わっていますから、問題が生じているデータ種類の送信ファイルは　アクセス権が解放されることは永遠になさそう？！時期は想像できません、ベンダさんが提供した処理なので

[退会済みユーザー]

pythonでの管理者権限での削除ですが、いくつか調べてみましたが、それらしいものは探し当てることができませんでした。
お役に立てずすみません。

[saya24]

了解です、調べてもらってすみません。

前回のテキストファイルが監視フォルダに残っていて上書きされただけでも、フリーソフトが　バットファイルを発火するよう　調整しましたので　大丈夫です。

本件一件落着とします、この御恩一生忘れません