Python Forum

Full Version: Code used to work 100%, now sometimes works!
You're currently viewing a stripped down version of our content. View the full version with proper formatting.
I have a remote server that records live TV. Every night I run a python script that copies new TV recordings to my local (home) PC over a VPN so I can watch those episodes at home.

Once the files are copied to my home PC, I run 2 'external' command line applications on them (comskip.exe - to remove commercials; and ccextractor.exe - to create an external .srt (subtitle) file).

the 2 'external' applications used to run 100% of the time, now, at best, they work 50% of the time. I get no errors, and my internal logs (from the script) don't show any glaring issues. The script seems to exit fine, as the last command is to write 'Applicaiton Finished' to a text file, which completes fine.

All PC's involved are Windows 11, and I believe I am on the latest version of Python (3.11.1).

I am happy to provide the entire script if needed, but the relevant 'Function()' is below. Can anyone tell me what might be causing it to not run the external applications sometimes?

def MoveFile(pFile, pDest):
    isFile = os.path.isfile(pFile)
    if isFile == True:
        dPath=os.path.dirname(pDest)
        isDir = os.path.isdir(dPath)
        if isDir == False:
            CreateFolder(dPath)
        
        os.system('move "%s" "%s"' % (pFile, pDest))
        WriteLog("Moved: '%s' to '%s'" % (pFile, pDest))
        
        if right(pDest, 3) == "mpg":
            #BEGIN CCEXTRATOR
            ccCmnd = [ccPath, pDest]
            WriteLog ("BEGIN: Closed Captions Extraction on %s: %s" % (pDest, ccCmnd))
            ccErrCode = subprocess.Popen(ccCmnd, stdin=subprocess.PIPE, stderr=subprocess.PIPE, stdout=subprocess.PIPE, shell=True)
            csCmnd = [csPath, "--ini=" + BasePath + "Comskip\\comskip.ini", pDest]
            WriteLog ("BEGIN: Comskip on %s: %s" % (pDest, csCmnd))
            csErrCode = subprocess.Popen(csCmnd, stdin=subprocess.PIPE, stderr=subprocess.PIPE, stdout=subprocess.PIPE, shell=True)
    else:
        WriteLog("Info: '%s' is not a file, so won't be moved." % pDest)
Are you getting "Moved" log messages for the files that are skipped?
(Jan-08-2023, 10:32 PM)deanhystad Wrote: [ -> ]Are you getting "Moved" log messages for the files that are skipped?
Yes, and the file is in fact copied to the correct location.

I'm wondering if it may be type of race condition. Where maybe it is trying to run the external apps, but for some reason the file isn't finalized or something. I did a test file, and the first time it failed to do comskip and ccextractor, but the 2nd time I tried, it worked fine. Same file.

I added a sleep command between the move command and the Popen command to see if it helps.
So the time.sleep command didn't make a difference. Last nights recording was transferred, but no comskip or ccexptractor was run. Here are the logs I generate to show that it at least is making through the code:

Quote:01/09/2023 12:30:09 AM: Application Started
01/09/2023 12:30:09 AM: Scanning EmbyServ3 File List
01/09/2023 12:30:09 AM: Moving file: //10.1.13.5/Channels/TV\NCIS Los Angeles\NCIS Los Angeles S14E09 Blood Bank 2023-01-08-2059.mpg
01/09/2023 12:36:50 AM: Moved: '//10.1.13.5/Channels/TV\NCIS Los Angeles\NCIS Los Angeles S14E09 Blood Bank 2023-01-08-2059.mpg' to 'R:\Recorded TV\NCIS Los Angeles\NCIS Los Angeles S14E09 Blood Bank 2023-01-08-2059.mpg'
01/09/2023 12:36:55 AM: BEGIN: Closed Captions Extraction on R:\Recorded TV\NCIS Los Angeles\NCIS Los Angeles S14E09 Blood Bank 2023-01-08-2059.mpg: ['E:\\OneDrive\\AutoCompress\\CCExtractor\\ccextractorwinfull.exe', 'R:\\Recorded TV\\NCIS Los Angeles\\NCIS Los Angeles S14E09 Blood Bank 2023-01-08-2059.mpg']
01/09/2023 12:36:55 AM: BEGIN: Comskip on R:\Recorded TV\NCIS Los Angeles\NCIS Los Angeles S14E09 Blood Bank 2023-01-08-2059.mpg: ['E:\\OneDrive\\AutoCompress\\Comskip\\comskip.exe', '--ini=E:\\OneDrive\\AutoCompress\\Comskip\\comskip.ini', 'R:\\Recorded TV\\NCIS Los Angeles\\NCIS Los Angeles S14E09 Blood Bank 2023-01-08-2059.mpg']
01/09/2023 12:36:55 AM: Channels DVR Pruner Response: 200
01/09/2023 12:36:55 AM: Application Ended
I updated that section of the code so that I would at least get error codes, and using a different mechanism to run the commands.

def MoveFile(pFile, pDest):
    isFile = os.path.isfile(pFile)
    if isFile == True:
        dPath=os.path.dirname(pDest)
        isDir = os.path.isdir(dPath)
        if isDir == False:
            CreateFolder(dPath)
        
        os.system('move "%s" "%s"' % (pFile, pDest))
        #shutil.move(pFile, pDest)
        WriteLog("Moved: '%s' to '%s'" % (pFile, pDest))
        
        if right(pDest, 3) == "mpg":
            time.sleep(5)
            #BEGIN CCEXTRATOR
            ccCmnd = [ccPath, "-delay",  "0", pDest]
            WriteLog ("BEGIN: Closed Captions Extraction on %s: %s" % (pDest, ccCmnd))
            ccErrCode = subprocess.run(ccCmnd)
            if str(ccErrCode.returncode) == "0":
                WriteLog ("SUCCESS!! - Closed Captions")
            else:
                WriteLog ("ERROR!! - Closed Captions failed with the following: %s" % ccErrCode)
            #END CCEXTRATOR    
            
            #COMSKIP
            WriteLog ("BEGIN: Comskip on %s" % pDest)
            csErrCode = subprocess.run([csPath, "--ini=" + BasePath + "Comskip/comskip.ini", pDest])
            
            if str(csErrCode.returncode) == "0" or str(csErrCode.returncode) == "1":
                WriteLog ("SUCCESS!! - Comskip")
            else: 
                WriteLog ("ERROR!! - Comskip failed with the following: %s." % str(csErrCode))
            #END COMSKIP
    else:
        WriteLog("Info: '%s' is not a file, so won't be moved." % pDest)
So it's been 2 nights and roughly 10 files transferred, and they have all worked like they should. So, I guess there was an issue with how I was using pOpen. Changing the code works great now.