fidlcat: Guide

Launching fidlcat

For information about launching fidlcat: fidlcat.

Default display

The default display for fidlcat is:

echo_client_cpp_synchronous 180768:180781 zx_channel_call(handle:handle: 14b21e1b, options:uint32: 0, deadline:time: ZX_TIME_INFINITE, rd_num_bytes:uint32: 65536, rd_num_handles:uint32: 64)
  sent request fidl.examples.echo/Echo.EchoString = {
    value: string = "hello synchronous world"
  }
  -> ZX_OK
    received response fidl.examples.echo/Echo.EchoString = {
      response: string = "hello synchronous world"
    }

We have the following information:

  • echo_client_cpp_synchronous: the name of the application which has generated this display.

  • 180768: the process koid.

  • 180781: the thread koid.

  • zx_channel_call: the name of the intercepted/displayed system call.

  • all the basic input parameters of the system call (here handle and options).

    For each one, we have:

    • The name of the parameter in black.

    • The type of the parameter in green.

    • The value of the parameter (the color depends on the parameter type).

  • all the complex input parameters. Here we display a FIDL message. This is a request which is sent by our application.

The display stops here. It will resume when the system call returns (sometimes it can be a very long time). For one thread, there will be no other display between the input arguments and the returned value. However, another thread display may be interleaved. When the system call returns, we display:

  • The returned value (-> ZX_OK)

  • The basic output parameters (there is no basic output parameters in this example).

  • The complex output parameters. Here we display a FIDL message. This is the response we received to the request we sent.

For zx_channel_read we can have this display:

echo_client_rust 256109:256122 zx_channel_read(handle:handle: e4c7c57f, options:uint32: 0, num_bytes:uint32: 48, num_handles:uint32: 0)
  -> ZX_OK
    received response fidl.examples.echo/Echo.EchoString = {
      response: string = "hello world!"
    }

But, if there is an error, we can have:

echo_client_rust 256109:256122 zx_channel_read(handle:handle: e4c7c57f, options:uint32: 0, num_bytes:uint32: 0, num_handles:uint32: 0)
  -> ZX_ERR_SHOULD_WAIT

Or:

echo_client_rust 256109:256122 zx_channel_read(handle:handle: e4c7c57f, options:uint32: 0, num_bytes:uint32: 0, num_handles:uint32: 0)
  -> ZX_ERR_BUFFER_TOO_SMALL (actual_bytes:uint32: 48, actual_handles:uint32: 0)

In this last case, even if the system call fails, we have some valid output parameters. actual_bytes and actual_handles give the minimal values which should have been used to call zx_channel_read.

Modifying the display

By default, we only display the process information on the first line.

Eventually, we also display the process information before the returned value if a system call from another thread has been displayed between the call and the returned value:

ledger.cmx 5859666:5861991 zx_channel_write(handle:handle: 035393df, options:uint32: 0)
  sent request fuchsia.io/Directory.Open = {
    flags: uint32 = 12582912
    mode: uint32 = 0
    path: string = "29/cache/cached_db"
    object: handle = 03f3b46b
  }

ledger.cmx 5859666:5859693 zx_channel_write(handle:handle: 035393df, options:uint32: 0)
  sent request fuchsia.io/Directory.Open = {
    flags: uint32 = 13107200
    mode: uint32 = 0
    path: string = "."
    object: handle = 0053b5fb
  }

ledger.cmx 5859666:5861991   -> ZX_OK

ledger.cmx 5859666:5859693   -> ZX_OK

Using the flag --with-process-info, we can display the process information on each line:

echo_client_rust 305640:305653 zx_channel_write(handle:handle: 4446ec4b, options:uint32: 0)
echo_client_rust 305640:305653   sent request fidl.examples.echo/Echo.EchoString = {
echo_client_rust 305640:305653     value: string = "hello world!"
echo_client_rust 305640:305653   }
echo_client_rust 305640:305653   -> ZX_OK

This is very useful if we want to do a grep on the output (for example, to only select one thread).

Interpreting the display

Most of the time we want to link several messages to be able to understand what our program is doing.

In this example:

ledger.cmx 5859666:5859693 zx_channel_create(options:uint32: 0)
  -> ZX_OK (out0:handle: 0243b493, out1:handle: 0163b42b)

ledger.cmx 5859666:5859693 zx_channel_write(handle:handle: 035393df, options:uint32: 0)
  sent request fuchsia.io/Directory.Open = {
    flags: uint32 = 12582912
    mode: uint32 = 0
    path: string = "29"
    object: handle = 0163b42b
  }
  -> ZX_OK

ledger.cmx 5859666:5859693 zx_channel_read(handle:handle: 0243b493, options:uint32: 1, num_bytes:uint32: 64, num_handles:uint32: 1)
  -> ZX_OK
    received response fuchsia.io/Node.OnOpen = {
      s: int32 = -25
      info: fuchsia.io/NodeInfo = null
    }

ledger.cmx 5859666:5859693 zx_channel_read(handle:handle: 0203b493, options:uint32: 1, num_bytes:uint32: 64, num_handles:uint32: 1)
  -> ZX_OK
    received response fuchsia.io/Node.OnOpen = {
      s: int32 = 0
      info: fuchsia.io/NodeInfo = { directory: fuchsia.io/DirectoryObject = {} }
    }

ledger.cmx 5859666:5859693 zx_channel_call(handle:handle: 0203b493, options:uint32: 0, deadline:time: ZX_TIME_INFINITE, rd_num_bytes:uint32: 24, rd_num_handles:uint32: 0)
  sent request fuchsia.io/Node.Close = {}
  -> ZX_OK
    received response fuchsia.io/Node.Close = {
      s: int32 = 0
    }

We first create a channel. The two handles 0243b493 and 0163b42b are linked. That means that a write on one handle will result on a read on the other handle.

We use handle 0163b42b in the Directory.Open message. That means that the associated handle (0243b493) is the handle which controls the directory we just opened.

When we receive Node.OnOpen on 0243b493 we know that it's a response to our Directory.Open. We also used the handle to call Node.Close.

Stack frames

By default, only the system calls are displayed. However, it's sometime interesting to know where a system call has been called. Using the flag --stack we can display the stack frames for every system call.

By default (--stack=0), the stack frames are not displayed.

With --statck=1 only the call site (1 to 4 frames) is displayed:

echo_client_cpp 5231515:5231528 at zircon/system/ulib/fidl/message.cc:62 fidl::Message::Read
echo_client_cpp 5231515:5231528 zx_channel_read(handle:handle: a0575917, options:uint32: 0, num_bytes:uint32: 65536, num_handles:uint32: 64)
  -> ZX_OK
    received response fidl.examples.echo/Echo.EchoString = {
      response: string = "hello world"
    }

This option doesn't add any overhead (except for the display).

With --stack=2 all the frames are displayed:

echo_client_cpp 5234749:5234762 at zircon/third_party/ulib/musl/src/env/__libc_start_main.c:74 start_main
echo_client_cpp 5234749:5234762 at garnet/examples/fidl/echo_client_cpp/echo_client.cc:40 main
echo_client_cpp 5234749:5234762 at zircon/system/ulib/async-loop/loop_wrapper.cc:25 async::Loop::Run
echo_client_cpp 5234749:5234762 at zircon/system/ulib/async-loop/loop.c:241 async_loop_run
echo_client_cpp 5234749:5234762 at zircon/system/ulib/async-loop/loop.c:284 async_loop_run_once
echo_client_cpp 5234749:5234762 at zircon/system/ulib/async-loop/loop.c:335 async_loop_dispatch_wait
echo_client_cpp 5234749:5234762 at sdk/lib/fidl/cpp/internal/message_reader.cc:165 fidl::internal::MessageReader::CallHandler
echo_client_cpp 5234749:5234762 at sdk/lib/fidl/cpp/internal/message_reader.cc:177 fidl::internal::MessageReader::OnHandleReady
echo_client_cpp 5234749:5234762 at sdk/lib/fidl/cpp/internal/message_reader.cc:201 fidl::internal::MessageReader::ReadAndDispatchMessage
echo_client_cpp 5234749:5234762 at zircon/system/ulib/fidl/message.cc:62 fidl::Message::Read
echo_client_cpp 5234749:5234762 zx_channel_read(handle:handle: a95c4cdf, options:uint32: 0, num_bytes:uint32: 65536, num_handles:uint32: 64)
  -> ZX_OK
    received response fidl.examples.echo/Echo.EchoString = {
      response: string = "hello world"
    }

This option adds some overhead because we need to ask zxdb for the full stack for each system call (and fidlcat becomes even more verbose). You should use it only when you need to understand what part of your code called the system calls.

Exceptions

Sometimes, your program crashes. If it's monitored by fidlcat you automatically have a stack where it crashed.

For example:

echo_server_cpp.cmx 1707964:1707977 zx_channel_read(handle:handle: ca322b6f, options:uint32: 0, num_bytes:uint32: 65536, num_handles:uint32: 64)
  -> ZX_OK
    received request fidl.examples.echo/Echo.EchoString = {
      value: string = "hello world"
    }

echo_server_cpp.cmx 1707964:1707977 at zircon/third_party/ulib/musl/src/env/__libc_start_main.c:93 start_main
echo_server_cpp.cmx 1707964:1707977 at garnet/examples/fidl/echo_server_cpp/echo_server.cc:15 main
echo_server_cpp.cmx 1707964:1707977 at zircon/system/ulib/async-loop/loop_wrapper.cc:21 async::Loop::Run
echo_server_cpp.cmx 1707964:1707977 at zircon/system/ulib/async-loop/loop.c:194 async_loop_run
echo_server_cpp.cmx 1707964:1707977 at zircon/system/ulib/async-loop/loop.c:236 async_loop_run_once
echo_server_cpp.cmx 1707964:1707977 at zircon/system/ulib/async-loop/loop.c:277 async_loop_dispatch_wait
echo_server_cpp.cmx 1707964:1707977 at sdk/lib/fidl/cpp/internal/message_reader.cc:165 fidl::internal::MessageReader::CallHandler
echo_server_cpp.cmx 1707964:1707977 at sdk/lib/fidl/cpp/internal/message_reader.cc:177 fidl::internal::MessageReader::OnHandleReady
echo_server_cpp.cmx 1707964:1707977 at sdk/lib/fidl/cpp/internal/message_reader.cc:228 fidl::internal::MessageReader::ReadAndDispatchMessage
echo_server_cpp.cmx 1707964:1707977 at sdk/lib/fidl/cpp/internal/stub_controller.cc:32 fidl::internal::StubController::OnMessage
echo_server_cpp.cmx 1707964:1707977 at fidling/gen/garnet/examples/fidl/services/fidl/examples/echo/cpp/fidl.cc:152 fidl::examples::echo::Echo_Stub::Dispatch_
echo_server_cpp.cmx 1707964:1707977 at garnet/examples/fidl/echo_server_cpp/echo_server_app.cc:22 echo::EchoServerApp::EchoString
echo_server_cpp.cmx 1707964:1707977 thread stopped on exception

You have the stack frames for the exception even if you didn't ask for the stack frames with the --stack options.

Syscalls

By default, fidlcat only displays the zx_channel syscalls.

You can display all the syscalls and choose which ones you want to display.

The --syscalls option let you define a regular expression which selects the syscalls to decode and display.

It can be passed multiple times.

To display all the syscalls, use: --syscalls=".*"

The --exclude-syscalls flag lets you exclude some syscalls selected by --syscalls. It's a regular expression which selects the syscalls to not decode and display.

It can be passed multiple times.

To be displayed, a syscall must satisfy the --syscalls pattern and not satisfy the --exclude-syscalls pattern.

To display all the syscalls but the zx_handle syscalls, use:

--syscalls ".*" --exclude-syscalls "zxhandle.*"