Recording Lost

[aderlopas]

Hello, 

Something strange has happened with a recurring (keyword) recording that I have scheduled.
recording was done, transcoded, and my postprocessing.bat was executed to move the whole directory including this recording to another drive succesfully.
Also npvr.db3 update command was updated with new filename based on OID provided to the batchprocessing.bat (%3 parameter), using the below command (which was tested working in the past):

call "C:\Users\Public\NPVR-data\sqlite3.exe" "C:\Users\Public\NPVR-data\npvr.db3" "update `SCHEDULED_RECORDING` set `filename`='D:%~p1%~n1%~x1' where `oid`=%3;" ".exit" >> "C:\Users\Public\NPVR-data\logs\recordings.log"

However, filename field inside npvr.db3 was not updated and it still has the value: [Default]

I am wondering what may have happened (most likely %3 parameter was not correctly populated? but I was not echoing the parameter in the log, I have changed the .bat file now to echo the parameters as well to a log). If so, why?

Please note that this scheduled recording was a special one as the TV played two episodes at once, one after the other (the recording resulted 6GB file as I am also pre-padding and post-padding 1 hour).

From the filename and directory structure, I did not see any episode number created so could it be that %3 parameter was null? (and hence my SQL update failed to locate the record?)

Also, having the attached XML, I tried to change the drive letter and import it but it still was not imported. Any help to import it would be appreciated.

Thanks and regards

Argyrios

[aderlopas]

Also attaching postprocessing.bat

[aderlopas]

Recording.log showing postprocessing.bat execution finished successfully...

Finished recording "C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts" at 3:00:00.56 on Tue 03/10/2020
C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts -> D:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts
C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.xml -> D:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.xml
2 File(s) copied
Post Processing Completed at 3:07:20.51 on Tue 03/10/2020

[mvallevand]

Do you have that file you append too?

>> "C:\Users\Public\NPVR-data\logs\recordings.log"

Martin

[aderlopas]

Do you have that file you append too?

>> "C:\Users\Public\NPVR-data\logs\recordings.log"

Martin

Sure Martin, here it is attached.

[mvallevand]

Since they still say "Default" with status 0 then NextPVR was having trouble updating the recording status. You would need to include logs, but perhaps your script is locking the database so NextPVR can't work correctly.

Martin

[aderlopas]

Since they still say "Default" with status 0 then NextPVR was having trouble updating the recording status.  You would need to include logs, but perhaps your script is locking the database so NextPVR can't work correctly.

Martin

Thanks Martin, 


Please find the logs attached. The Server was restarted since then so I hope the logs are still there.
But I would assume that execution of postprocessing.bat begins after all original recording tasks have completed (otherwise it would not be really post-processing   right?)

[sub]

It looks like the this was the arguments passed by NextPVR, and the processing that you tried to do:

2020-03-10 03:00:00.409 [DEBUG][9] Starting: C:\Users\Public\NPVR-data\scripts\PostProcessing.bat "C:\TV Recordings\Luther\[K16] Luther - 1ος Κύκλος_20200309_23450200.ts" 13 989 23 "[K16] Luther - 1ος Κύκλος"
2020-03-10 03:00:00.577 [DEBUG][319]
2020-03-10 03:00:00.577 [DEBUG][319] C:\Users\Public\NPVR-data\scripts>ECHO Finished recording "C:\TV Recordings\Luther\[K16] Luther - 1ος Κύκλος_20200309_23450200.ts" at 3:00:00.56 on Tue 03/10/2020 1>>"C:\Users\Public\NPVR-data\logs\recordings.log"
2020-03-10 03:00:00.586 [DEBUG][319]
2020-03-10 03:00:00.586 [DEBUG][319] C:\Users\Public\NPVR-data\scripts>xcopy "C:\TV Recordings\Luther\*.*" "D:\TV Recordings\Luther\" /e /f /J /Y 1>>"C:\Users\Public\NPVR-data\logs\recordings.log"
2020-03-10 03:07:20.042 [DEBUG][319]
2020-03-10 03:07:20.043 [DEBUG][31] C:\Users\Public\NPVR-data\scripts>call "C:\Users\Public\NPVR-data\sqlite3.exe" "C:\Users\Public\NPVR-data\npvr.db3" "update `SCHEDULED_RECORDING` set `filename`='D:\TV Recordings\Luther\[K16] Luther - 1ος Κύκλος_20200309_23450200.ts' where `oid`=989;" ".exit" 1>>"C:\Users\Public\NPVR-data\logs\recordings.log"
2020-03-10 03:07:20.466 [DEBUG][31]
2020-03-10 03:07:20.466 [DEBUG][31] C:\Users\Public\NPVR-data\scripts>rmdir "C:\TV Recordings\Luther\" /s /q
2020-03-10 03:07:20.522 [DEBUG][31]
2020-03-10 03:07:20.522 [DEBUG][31] C:\Users\Public\NPVR-data\scripts>ECHO Post Processing Completed at 3:07:20.51 on Tue 03/10/2020 1>>"C:\Users\Public\NPVR-data\logs\recordings.log"

[sub]

Given the output you ended up with in "C:\Users\Public\NPVR-data\logs\recordings.log", it looks like something wasn't liking something about your national character set

Finished recording "C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts" at 3:00:00.56 on Tue 03/10/2020
C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts -> D:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts
C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.xml -> D:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.xml
2 File(s) copied
Post Processing Completed at 3:07:20.51 on Tue 03/10/2020

[aderlopas]

Given the output you ended up with in "C:\Users\Public\NPVR-data\logs\recordings.log", it looks like something wasn't liking something about your national character set

Finished recording "C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts" at 3:00:00.56 on Tue 03/10/2020
C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts -> D:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.ts
C:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.xml -> D:\TV Recordings\Luther\[K16] Luther - 1¦ ‰η΅Ά¦_20200309_23450200.xml
2 File(s) copied
Post Processing Completed at 3:07:20.51 on Tue 03/10/2020

Thanks sub for your reply. I changed my postprocessing.bat to set the correct Greek codepage (Windows-1253):
by adding the command:

chcp 1253>NUL

But Is this really the problem?

I see from the logs you reference the OID passed to the .bat file was 989:

`oid`=989

However in my database it only exist OID=991 and 992 if you take a look at the screenshots I uploaded. 
This is why the update failed most likely...

any ideas why the wrong OID was passed to the .bat file?