@@ -440,25 +440,64 @@ def _nonblocking_write_to_stdout(messages: Iterable[str]) -> None:
440440
441441 logger = logging .getLogger ("airbyte_cdk.stdout_writer" )
442442 _BLOCK_LOG_THRESHOLD_S = 5.0 # log when a single write blocks longer than this
443+ _HEARTBEAT_INTERVAL_S = 30.0 # emit a heartbeat to stderr every 30s
443444 messages_written = 0
444445 bytes_written = 0
445446 last_write_ts = time .monotonic ()
446447 total_blocked_s = 0.0
447448 block_count = 0
449+ pipe_blocked = False # True while os.write() is in progress
450+ pipe_blocked_since = 0.0 # monotonic timestamp when current os.write() started
451+ heartbeat_stop = threading .Event ()
452+
453+ def _heartbeat () -> None :
454+ """Emit periodic status to stderr so we can prove pipe-blocking in Cloud logs.
455+
456+ This thread writes directly to fd 2 (stderr) which is collected by the
457+ Kubernetes container runtime independently of the orchestrator that reads
458+ stdout. Even when the orchestrator stops reading stdout, these heartbeat
459+ lines should still appear in the Cloud job logs.
460+ """
461+ start = time .monotonic ()
462+ stderr_fd = 2 # write directly to fd 2, bypassing Python buffering
463+ while not heartbeat_stop .wait (timeout = _HEARTBEAT_INTERVAL_S ):
464+ now = time .monotonic ()
465+ elapsed_total = now - start
466+ blocked_str = "YES" if pipe_blocked else "NO"
467+ blocked_dur = f" blocked_since={ now - pipe_blocked_since :.0f} s" if pipe_blocked else ""
468+ line = (
469+ f"STDOUT_WRITER_HEARTBEAT: t={ elapsed_total :.0f} s "
470+ f"msgs={ messages_written } bytes={ bytes_written } "
471+ f"pipe_blocked={ blocked_str } { blocked_dur } "
472+ f"queue={ write_queue .qsize ()} /{ _WRITE_QUEUE_SIZE } \n "
473+ )
474+ try :
475+ os .write (stderr_fd , line .encode ())
476+ except OSError :
477+ pass # stderr itself might be broken; nothing we can do
478+
479+ heartbeat_thread = threading .Thread (
480+ target = _heartbeat , name = "stdout-writer-heartbeat" , daemon = True
481+ )
482+ heartbeat_thread .start ()
448483
449484 def _stdout_writer () -> None :
450485 """Dedicated thread that writes queued messages to stdout."""
451486 nonlocal messages_written , bytes_written , last_write_ts , total_blocked_s , block_count
487+ nonlocal pipe_blocked , pipe_blocked_since
452488 try :
453489 while True :
454490 data = write_queue .get ()
455491 if data is None :
456492 break
457493 total = 0
458494 while total < len (data ):
459- before = time .monotonic ()
495+ pipe_blocked = True
496+ pipe_blocked_since = time .monotonic ()
497+ before = pipe_blocked_since
460498 written = os .write (real_fd , data [total :])
461499 elapsed = time .monotonic () - before
500+ pipe_blocked = False
462501 total += written
463502 if elapsed >= _BLOCK_LOG_THRESHOLD_S :
464503 block_count += 1
@@ -485,6 +524,13 @@ def _stdout_writer() -> None:
485524
486525 writer = threading .Thread (target = _stdout_writer , name = "stdout-writer" , daemon = True )
487526 writer .start ()
527+ logger .info (
528+ "STDOUT_WRITER: started writer_thread fd=%d queue_size=%d watchdog=%ds heartbeat=%ds" ,
529+ real_fd ,
530+ _WRITE_QUEUE_SIZE ,
531+ _WATCHDOG_TIMEOUT_S ,
532+ int (_HEARTBEAT_INTERVAL_S ),
533+ )
488534
489535 try :
490536 last_progress = time .monotonic ()
@@ -525,6 +571,7 @@ def _stdout_writer() -> None:
525571 "Terminating process to prevent indefinite hang."
526572 )
527573 finally :
574+ heartbeat_stop .set ()
528575 # Signal writer to drain remaining messages and exit.
529576 write_queue .put (None )
530577 writer .join (timeout = 30 )
0 commit comments