Automated Image Uploads Stopped for 4 Days: ssh Chosen by PATH

I have four automated jobs that run every night. They pull new data into the database, then upload the related image files to the destination server. Every morning I checked the logs and saw the same line, {"ok":true,"imported":152}, so I assumed everything was working.

Then someone pointed out that images across the website were broken. I checked and found that the new content had indeed been published every day, but every image it referenced returned 404. Tracing it back, I found that uploads had been broken for four full days, with every run reporting success. This article records where the trap was and how I closed it. All host values, ports, and key filenames in this article have been replaced with example values.

Symptoms: all the new content arrived, but every image was missing

These jobs all follow the same structure: incoming data is fetched entirely over HTTP, without touching ssh. Outgoing image uploads use scp, which uses ssh.

When file transfers failed, the reporting code read only the data-fetching result, so it kept showing ok:true every day. The result was new entries on the website pointing to image filenames that had never been uploaded.

The cause: one line that let PATH decide

The code responsible looked perfectly ordinary, and I believe almost everyone has written something like it:

# ตัวที่พาไปตาย - ระบุแค่ชื่อ ปล่อยให้ระบบไปหาเอาเองว่าไบนารีตัวไหน
subprocess.run(["ssh", "-i", KEY, HOST, "mkdir -p /var/www/img"])
subprocess.run(["scp", "-i", KEY] + files + [f"{HOST}:/var/www/img/"])

subprocess does not choose the binary itself. It hands that off to the system to search the PATH of the calling process, which means the actual binary depends on who launches it. My Windows machine has several copies of ssh.exe installed:

Get-Command ssh -All | Select-Object -ExpandProperty Source
# %USERPROFILE%\miniconda3\Library\usr\bin\ssh.exe     <- MSYS ต่อได้
# C:\Program Files\Git\usr\bin\ssh.exe
# C:\WINDOWS\System32\OpenSSH\ssh.exe                  <- ต่อไม่ได้ ค้างเงียบ

When I ran it manually from my own PowerShell window, PATH selected the MSYS version bundled with miniconda, which connected normally. But when a separate scheduler launched the job, it used a different environment. Its PATH selected the OpenSSH bundled with Windows instead, and that version could not connect to this destination — sometimes returning Connection closed, sometimes hanging until it timed out.

How to confirm it: compare server file timestamps with job dates

When tracing when it had stopped working, I used the only method I could trust: checking the actual files on the server, rather than my own logs, because those logs were already lying.

ssh srv1 "ls -lt /var/www/img | head -5"
ssh srv1 "find /var/www/img -type f -newermt '-7 days' | wc -l"

First fix: probe the actual binary before using it

I stopped trusting PATH entirely and wrote a helper that tries each candidate in turn, sending one real command. It remembers whichever one responds correctly and uses it for the entire run. For scp, it uses the binary in the same folder as the selected ssh.

import os, shutil, subprocess

class Deploy:
    def _pick(self):
        """ไบนารีตัวแรกที่ตอบกลับมาจริง - ลำดับใน PATH เชื่อไม่ได้"""
        cands = [os.path.expanduser(r"~\miniconda3\Library\usr\bin\ssh.exe"),
                 os.path.expanduser(r"~\anaconda3\Library\usr\bin\ssh.exe"),
                 shutil.which("ssh"),
                 r"C:\Program Files\Git\usr\bin\ssh.exe",
                 r"C:\WINDOWS\System32\OpenSSH\ssh.exe"]
        tried = []
        for s in cands:
            if not s or not os.path.exists(s) or s.lower() in tried:
                continue
            tried.append(s.lower())
            try:
                r = subprocess.run([s] + self.base + [self.host, "echo SSHOK"],
                                   capture_output=True, timeout=40)
            except Exception:
                continue
            if b"SSHOK" in r.stdout:
                c = os.path.join(os.path.dirname(s), "scp.exe")
                return s, (c if os.path.exists(c) else "scp")
        self.problems.append("no working ssh found (tried %d)" % len(tried))
        return "ssh", "scp"

The self.base options I always include prevent it from waiting for anything along the way:

self.base = ["-i", key, "-o", "BatchMode=yes", "-o", "IdentitiesOnly=yes",
             "-o", "StrictHostKeyChecking=accept-new", "-o", "ConnectTimeout=15"]

Second fix: split scp into batches of 40 files

Once the connection worked, I immediately hit the next wall. While uploading the backlog of nearly three hundred files, a single scp command containing more than a hundred long paths would hit Windows' command-line length limit of 8191 characters. The command would get cut off midway and fail in a confusing way. The fix was to split the files into batches of 40 and upload them in a loop.

def push(self, files, destdir, chunk=40):
    """scp ทีละชุด - ชุดเดียว 150 พาธจะชนเพดาน 8191 ตัวอักษรของ Windows"""
    ok, errs = 0, []
    for i in range(0, len(files), chunk):
        c = files[i:i + chunk]
        r = subprocess.run([self.scp_bin] + self.base + ["-q"] + c +
                           ["%s:%s/" % (self.host, destdir.rstrip("/"))],
                           capture_output=True, timeout=900)
        if r.returncode == 0:
            ok += len(c)
        else:
            errs.append(r.stderr.decode("utf-8", "replace").strip()[:120]
                        or "rc=%d" % r.returncode)
    return ok, errs

This was where I first actually used returncode and passed it along so the reporting code could see it.

Another trap: directories created over ssh get 744 permissions and the web returns 403

Another issue cost me half a day: after using mkdir over ssh to create a new image folder, every file uploaded successfully, but accessing anything in that folder through the web returned 403. The cause was the umask of the session opened by ssh, which gave new directories 744 permissions that prevented the web user from accessing them. I had to follow up with chmod every time.

def mkdir(self, remotedir):
    """mkdir -p + chmod 755 - ไดเรกทอรีที่ ssh สร้างได้ 744 แล้วเว็บ 403"""
    return self.sh("mkdir -p %s && chmod 755 %s" % (remotedir, remotedir)).returncode

Completeness check: do not declare success while anything is missing

The most useful addition I made was not a bug fix, but a final check. The rule is simple: every file referenced by published content must actually exist on the host. If any are missing, retry uploading them immediately, and if they are still missing, record the problem.

def gate(self, names, srcdir, destdir, label=None):
    """ทุกไฟล์ที่เนื้อหาอ้างถึงต้องอยู่บนโฮสต์ - ขาดคือตามส่ง ขาดต่อคือรายงาน"""
    names = {os.path.basename(n) for n in names if n}
    if not names:
        return "no refs"
    missing = sorted(names - self.ls(destdir))
    if not missing:
        return "OK %d/%d on host" % (len(names), len(names))
    local = [os.path.join(srcdir, m) for m in missing
             if srcdir and os.path.exists(os.path.join(srcdir, m))]
    repushed = self.push(local, destdir)[0] if local else 0
    still = sorted(names - self.ls(destdir))
    no_local = [m for m in missing
                if not (srcdir and os.path.exists(os.path.join(srcdir, m)))]
    if still:
        self.problems.append("%s: %d referenced files STILL missing (%s)"
                             % (label, len(still), still[:3]))
    if no_local:
        self.problems.append("%s: %d referenced files have NO local source (%s)"
                             % (label, len(no_local), no_local[:3]))
    return "re-pushed %d/%d | still-missing %d | no-local %d" % (
        repushed, len(missing), len(still), len(no_local))

I deliberately separate still-missing from no-local. The first means the file exists locally but could not be uploaded, which is a connection problem. The second means the content references a file that was never created in the first place, which is a different gap requiring a different fix.

The final report must be prominent and return a nonzero exit code, or the caller above it has no way to know:

def report(self, name):
    print("[%s] ssh=%s" % (name, self.ssh_bin), flush=True)
    print("RESULT: %s" % ("OK" if not self.problems else "INCOMPLETE"), flush=True)
    for p in self.problems:
        print("  PROBLEM: %s" % p, flush=True)
    return 1 if self.problems else 0

For jobs launched directly from .bat where nothing reads stdout, I instead have them leave a problem report file in a folder I check every morning:

@echo off
"%USERPROFILE%\miniconda3\envs\ml313\python.exe" "C:\jobs\publish.py" >> "C:\jobs\run.log" 2>&1
if errorlevel 1 echo publish failed %date% %time% > "C:\jobs\inbox\job-problem.txt"

1. Stop calling binaries by their bare names. Probe the actual binary with a command that must return a response.
2. Check returncode every time. Never discard it. If you will not check it, do not make the call.
3. Split files into batches before uploading. Keep the command line within the system's length limit.
4. Always follow directory creation with chmod. Do not trust the session's umask.
5. Finish with a completeness check and let it decide whether the job passes or fails.

Conclusion

I took three main lessons from this work.

First — an external command called by its bare name is not always the same command. It is "whatever the caller's PATH points to," which can change at any time without a single change to the code.

Second — the return value from an external command is not decoration. Choosing not to read it means choosing not to know when it breaks.

Third — an automated job needs a final check that inspects what is actually at the destination, rather than whether the code reached the end. Those are very different things.

If you have automated jobs that have always reported success, try checking the actual files at the destination when you have a moment. I have learned that the numbers in the logs and the files on disk can disagree for longer than I expected. If I have missed anything in the explanation or made a typo, I will come back and correct it later.