Repository: skypilot-org/skypilot
Pull request: [UX] remove stacktrace for pipe and ssh info
Closes #1169 

This PR removes the long stack trace due to the broken pipe. (The `--no-follow` is a better way to get rid of the broken pipe issue.)

Tested:
```
sky logs test-log | grep il                         
Tailing logs of the last job on cluster 'test-log'...
INFO: Tip: use Ctrl-C to exit log streaming (task will not be killed).
INFO: Waiting for task resources on 1 node. This will block if the cluster is full.
^C
Aborted!
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'>
BrokenPipeError: [Errno 32] Broken pipe
```

Problem statement:
Make `sky logs` with piping handle interrupts gracefully
If using `sky logs .. | grep ...` in a pipe, then ctrl-c would print out a long stacktrace:
```
$ sky logs sky-spot-controller-abb92b6d 34 | grep 'preempted from'
(zh-14-26 pid=97928) I 09-13 04:21:03 recovery_strategy.py:355] Cluster is preempted from zone us-west1-a.
(zh-14-26 pid=97928) I 09-13 05:31:15 recovery_strategy.py:355] Cluster is preempted from zone us-west1-b.
^C--- Logging error ---
Traceback (most recent call last):
  File "/opt/conda/lib/python3.9/logging/__init__.py", line 1087, in emit
    self.flush()
BrokenPipeError: [Errno 32] Broken pipe
Call stack:
  File "/home/ubuntu/.local/bin/sky", line 8, in <module>
    sys.exit(cli())
  File "/home/ubuntu/.local/lib/python3.9/site-packages/click/core.py", line 1128, in __call__
    return self.main(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/click/core.py", line 1053, in main
    rv = self.invoke(ctx)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/utils/common_utils.py", line 147, in _record
    return f(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/cli.py", line 776, in invoke
    return super().invoke(ctx)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/ubuntu/.local/lib/python3.9/site-packages/click/core.py", line 1395, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/utils/common_utils.py", line 168, in _record
    return f(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/cli.py", line 1210, in logs
    core.tail_logs(cluster, job_id)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/core.py", line 354, in tail_logs
    backend.tail_logs(handle, job_id)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/backends/cloud_vm_ray_backend.py", line 2403, in tail_logs
    returncode = self.run_on_head(
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/utils/common_utils.py", line 168, in _record
    return f(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/backends/cloud_vm_ray_backend.py", line 2692, in run_on_head
    return runner.run(
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/utils/command_runner.py", line 255, in run
    return log_lib.run_with_log(' '.join(command),
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/skylet/log_lib.py", line 233, in run_with_log
    proc.wait()
  File "/opt/conda/lib/python3.9/subprocess.py", line 1189, in wait
    return self._wait(timeout=timeout)
  File "/opt/conda/lib/python3.9/subprocess.py", line 1917, in _wait
    (pid, sts) = self._try_wait(0)
  File "/opt/conda/lib/python3.9/subprocess.py", line 1875, in _try_wait
    (pid, sts) = os.waitpid(self.pid, wait_flags)
  File "/home/ubuntu/.local/lib/python3.9/site-packages/sky/backends/backend_utils.py", line 1909, in interrupt_handler
    logger.warning(f'{colorama.Fore.LIGHTBLACK_EX}The job will keep '
Message: '\x1b[90mThe job will keep running after Ctrl-C.\x1b[0m'
Arguments: ()
Shared connection to 44.210.146.121 closed.

Aborted!
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'>
BrokenPipeError: [Errno 32] Broken pipe
```

Hints from issue discussion:

Commit message: format

Patch to review:
diff --git a/sky/backends/backend_utils.py b/sky/backends/backend_utils.py
index 541d3bf96ef..1dc132ce221 100644
--- a/sky/backends/backend_utils.py
+++ b/sky/backends/backend_utils.py
@@ -1996,9 +1996,11 @@ def kill_children_processes():
 # Handle ctrl-c
 def interrupt_handler(signum, frame):
     del signum, frame
-    logger.warning(f'{colorama.Style.DIM}The job will keep '
-                   f'running after Ctrl-C.{colorama.Style.RESET_ALL}')
     kill_children_processes()
+    # Avoid using logger here, as it will print the stack trace for broken
+    # pipe, when the output is piped to another program.
+    print(f'{colorama.Style.DIM}Tip: The job will keep '
+          f'running after Ctrl-C.{colorama.Style.RESET_ALL}')
     with ux_utils.print_exception_no_traceback():
         raise KeyboardInterrupt(exceptions.KEYBOARD_INTERRUPT_CODE)
 
@@ -2006,9 +2008,11 @@ def interrupt_handler(signum, frame):
 # Handle ctrl-z
 def stop_handler(signum, frame):
     del signum, frame
-    logger.warning(f'{colorama.Style.DIM}The job will keep '
-                   f'running after Ctrl-Z.{colorama.Style.RESET_ALL}')
     kill_children_processes()
+    # Avoid using logger here, as it will print the stack trace for broken
+    # pipe, when the output is piped to another program.
+    print(f'{colorama.Style.DIM}Tip: The job will keep '
+          f'running after Ctrl-Z.{colorama.Style.RESET_ALL}')
     with ux_utils.print_exception_no_traceback():
         raise KeyboardInterrupt(exceptions.SIGTSTP_CODE)
 
diff --git a/sky/skylet/log_lib.py b/sky/skylet/log_lib.py
index dca32ec3c98..a8ede3f570c 100644
--- a/sky/skylet/log_lib.py
+++ b/sky/skylet/log_lib.py
@@ -417,6 +417,7 @@ def tail_logs(job_owner: str,
         time.sleep(_SKY_LOG_WAITING_GAP_SECONDS)
         status = job_lib.update_job_status(job_owner, [job_id], silent=True)[0]
 
+    start_stream_at = 'INFO: Tip: use Ctrl-C to exit log'
     if follow and status in [
             job_lib.JobStatus.RUNNING, job_lib.JobStatus.PENDING
     ]:
@@ -425,15 +426,19 @@ def tail_logs(job_owner: str,
         with open(log_path, 'r', newline='') as log_file:
             # Using `_follow` instead of `tail -f` to streaming the whole
             # log and creating a new process for tail.
-            for line in _follow_job_logs(
-                    log_file,
-                    job_id=job_id,
-                    start_streaming_at='INFO: Tip: use Ctrl-C to exit log'):
+            for line in _follow_job_logs(log_file,
+                                         job_id=job_id,
+                                         start_streaming_at=start_stream_at):
                 print(line, end='', flush=True)
     else:
         try:
+            start_stream = False
             with open(log_path, 'r') as f:
-                print(f.read())
+                for line in f.readlines():
+                    if start_stream_at in line:
+                        start_stream = True
+                    if start_stream:
+                        print(line, end='', flush=True)
         except FileNotFoundError:
             print(f'{colorama.Fore.RED}ERROR: Logs for job {job_id} (status:'
                   f' {status.value}) does not exist.{colorama.Style.RESET_ALL}')
diff --git a/sky/utils/command_runner.py b/sky/utils/command_runner.py
index 71652ccc90b..3eb0cea1450 100644
--- a/sky/utils/command_runner.py
+++ b/sky/utils/command_runner.py
@@ -68,6 +68,8 @@ def ssh_options_list(ssh_private_key: Optional[str],
         'ConnectTimeout': f'{timeout}s',
         # Agent forwarding for git.
         'ForwardAgent': 'yes',
+        # Disable loggings for ssh.
+        'LogLevel': 'QUIET',
     }
     if ssh_control_name is not None:
         arg_dict.update({


Code review comments:
diff_hunk: @@ -68,6 +68,8 @@ def ssh_options_list(ssh_private_key: Optional[str],
         'ConnectTimeout': f'{timeout}s',
         # Agent forwarding for git.
         'ForwardAgent': 'yes',
+        # Disable loggings for ssh.
+        'LogLevel': 'QUIET',
path: sky/utils/command_runner.py
text: @user2:
I think this change will also suppress helpful messages for users to debug their network. Is this change required/is there some other solution?

E.g., I tried sky logs with wifi off:
```
# On master, wifi off
(base) romilb@user1:/mnt/d/Romil/Berkeley/Research/sky-experiments/examples$ sky logs myclus 2
Tailing logs of job 2 on cluster 'myclus'...
ssh: connect to host 3.81.184.201 port 22: Connection refused

# This branch, wifi off
(base) romilb@user1:/mnt/d/Romil/Berkeley/Research/sky-experiments/examples$ sky logs myclus 2
Tailing logs of job 2 on cluster 'myclus'...
(base) romilb@user1:/mnt/d/Romil/Berkeley/Research/sky-experiments/examples$  # no error
```

@author:
Ahhh, that is a great catch! It was just for removing the `connection closed` logging, but it does not worth it to suppress the errors. Reverted. Thanks!