Watch Folder not picking up all files when a batch is placed in folder.

[SheldonABS]

Hi Team!

As of recent, the watch folders within our workflow have begun to randomly not pick up all files that are placed into the folder whenever we place files in the folder in batches. For example, we'll put a batch of 4-5 files into the watch folder in one go and all will be picked up and proceed through the workflow apart from 1 or 2 which are left in the folder. We noticed that this behaviour is quite random as sometimes everything is picked up and processed without any issues but other times this will occur. Re-placing the file into the folder does allow the file to be picked up and worked, however we want to avoid having to do this every time this happens to a file.

We have restarted the FFAStrans machine, alongside the machine that is used to place the files in the watch folder, in hopes that this would resolve the issue but post restart, this would still occur at random instances.

One thing to note is that we noticed that the filenames that do not get picked up by the watch folder appear in the "def_log" Logs however doesn't appear in the "monitor" Logs.

I have attached screenshots of the version numbers of all softwares we are using alongside the locations we are looking in, in terms of logging.

Are there any methods of troubleshooting we can try to resolve this?

Thanks!

[emcodem]

Hi Sheldon,

was waiting for steinar but he didnt have time yet to look into this. You have a pretty old version and there was lots of changes in this area so it is good to upgrade if you can.
Things you can do:

Uncheck "Skip Source verification" which disables ffastrans to try open the file for check if copy is finished
Always check "forget missing"
Use "check growing once"

If nothing of this helps, please make sure to give some details, e.g. a screenshot of your monitor settings or your full workflow uploaded - and information about the type of storage this watch is on as well as how the files are being put to the watchfolder, e.g. windows move/copy or ftp...

[SheldonABS]

Hi Emcodem,

Thanks for the suggestions! Unfortunately these haven't been able to resolve our issue.

While we have considered upgrading to a newer version, we cannot at the moment as we run a critical service using FFAStrans within our pipeline and so we would need to plan a window to complete the upgrades to ensure all aspects are checked and working, which isn't possible for us at the moment.

I have attached a screenshot of our monitor settings and regarding how the files are being put into the watch folder, we are performing a manual Windows copy of the file from a FTP to the watch folder using a Windows machine that has access to both locations.

One thing to also note, we are running the exact same workflow on a different instance of FFAStrans on a separate system that handles an identical workload to the instance of FFAStrans we are having this issue with, however we haven't noticed this issue on that machine. Both systems are identical in specs and storage too so we are really stuck on what is causing this.

Do let us know if you or anyone has any other ideas and I look forward to hearing back from you!

[emcodem]

Thanks for the details and sorry i mean "check" skip source validation, not "uncheck".
The "Localize file" is something i never used before, @admin to tell if it can influence this situation or not.

I'd really like you to test if the "Source verification" is the problem. However, you normally need this checked to support windows copy (the file size does not change and date handling varies on different storage types, so "open the file" is the only reliable way for ffastrans to check if its finished).
What you can do to still give it a test is first "Copy" the files into a non watched temporary location next to the watchfolder and then "move" the files to the watch.

[emcodem]

steinar says he suspects the issue with the code in 1.3 version and strongly recommends updating "even if it hurts"...

[SheldonABS]

Hi,

Unfortunately both options didn't seem to resolve either. I think it does just have to be updating the software on our side.

For now, we'll stick to manually re-placing the files in the watch folders and troubleshooting but we'll move these updates up in our timeline to try and get it sorted as soon as we can.

Thank you to you and steinar for the help and suggestions! If we do figure out anything that resolves this before we do the updates, I'll update the thread on the off chance that someone else may run into the same issue.

[emcodem]

OK sorry buddy. I'll leave you some additional informations about Watchfolders.

Imagine this folder structure:
C:\FFAStrans-Public-1.4.2\Processors\db\cache\wfs\WORKFLOW_ID\mons\NODE_ID

The NODE_ID is the ID of one Monitor Folder processor in a workflow.
All files that have been picked up (if file name filter matches) get a json file flat in this directory.
Moreover, there is a subfolder "i" (incoming) where we park a json file for each file in the watchfolder that is about to be processed. In this state, we do not yet have created a "job" but we do all the checks to see if we can create a "job" from the file (e.g. growing check).

So in short: directly in the folder NODE_ID you should see a json file for all files that did end up in a job and the i subfolder contains files that are detected in the watchfolder but not yet ready.

Also you can raise the log level: there are a few log lines in the watchfolder code that you only see in the def_log files when you set debug.extra_log in your ffastrans.json file to true. If you change that value, you have to stop and start the watchfolder to apply the changes - and make sure to revert the setting to false before you go home for the day.

Alternatively you may think about using webinterface job submission instead of moving files to folders.

[SheldonABS]

Hey Em,

With what you've mentioned here, we noticed that the files that are not getting picked up are actually being picked up and processed as the JSON file corresponding to the file was appearing in the "NODE_ID" folder.

I cross-checked the ID and traced it back to the full_log.json for that particular job and actually found that the file had been getting processed but had actually been failing at one of our nodes. This particular node, ID: 20220901-1214-1880-5d7b-f842fa4d69db, is a Conditional that check a bunch of parameters of the video file to ensure that it's the format we need it to be. One of these checks is ensuring that the start timecode of the video file is 00:00:00:00 and turns out the video files very rarely fail this for some reason despite the timecodes being correct. We missed this as the node is configured to dispel the job on a failed/false outcome and so doesn't appear in the status monitor / web interface.

From the .json Log, it seems that once the video reaches this node, an error occurs as followed:

{"created":"2026-02-12T14:40:35.859+00:00","node":{"id":"20220901-1214-1880-5d7b-f842fa4d69db","type":"op_cond"},"split_id":"142-1-13","event":"node end","type":"trace","context":"node execution","host":"RECTEST","data":{"status":"error","code":"","error":"9th evaluation of \"%s_start_tc% \u2260 00:00:00:00\" is \"00:00:00:00 \u2260 00:00:00:00\""}},

This then leads to the log file being created with the error:

{"created":"2026-02-12T14:40:35.916+00:00","split_id":"142-1-13","event":"Create full log file and close job","type":"sys","context":"ending job","host":"RECTEST","data":{"path":"C:\\FFAStrans1.3.1\\processors\\db\\cache\\jobs\\20260212-1440-1598-6a41-8103ee619fa6\\full_log.json","status":"Evaluating \"%s_start_tc%\" \u2260 \"00:00:00:00\"","code":"000000A9","error":"9th evaluation of \"%s_start_tc% \u2260 00:00:00:00\" is \"00:00:00:00 \u2260 00:00:00:00\""}}]

I have been trying to recreate this error however I'd only been able to replicate it twice after around 40+ attempts which is odd. One of the times was just replacing the file in the watch folder after moving it to a different location, however manually submitting the file caused the transcode to run as usual with no issues.

I have attached the full log in case it does help with any troubleshooting on your side but maybe this is just one of those occasional bugs that an update would solve?

Either way, thanks for the advice, it's helped us get this far which is good!

[emcodem]

Thats in deed good progress, timecode stuff is much easier to debug than watchfolder related matters.
Thanks for sharing the log, it would be good to see the worfklow for this too.

So from what i see in your log is that you check the timecode three times, 2x before and 1x after. FFprobe and Exiftool think after XDCAM encoder the Timecode is zero therefore the job exits.
After the encode, we see 2 conditionals being executed in parallel, one of them ending the job because it detected zero timecode.

We also see that exiftool and ffprobe report this zero timecode but mediainfo failing to analyze the file:

Code: Select all

Error getting mediainfo data from \"d:\\.ffastrans_work_root\\20230811-1111-1205-44e8-563dc83798e2\\20260212-1440-1598-6a41-8103ee619fa6\\1-0-0~260212144021384~3852~20180409-105545-004-98603cb0dfeb~enc_av_xdcamhd.mxf\"

I'm not sure what i see here, gotta ask steinar about it and let you know...

[SheldonABS]

No problems waiting for steniar's thoughts. In the mean time, I'll attach a copy of the workflow here for reference.

Thanks!