Skip to content

gz log record takes over 15 seconds to start #660

@jmgrosen

Description

@jmgrosen

Environment

  • OS Version: macOS Sequoia 15.5
  • Source or binary build? Source, release 13.4.1

Description

  • Expected behavior: Running gz log record -v4 takes a little over two seconds to print that it has started recording.
  • Actual behavior: Running gz log record -v4 takes over fifteen seconds to print that it has started recording.

I've tried running this command in an Ubuntu Docker container and it only takes a little over two seconds (a delay which is expected due to it waiting for two heartbeat intervals).

It seems to take this long no matter whether there are topics actually being published or not.

From some cursory looks over a profile I took, I noticed two odd things:

  • It takes ten seconds (nearly exactly) after libgz-transport13-log.13.4.1.dylib is dlopened for libstdc++.6.dylib to be dlopened. This timing is consistent across runs.
  • Once libstdc++ is loaded, sockets are bound almost immediately, but it then takes five more seconds before the log about recording starting is printed (instead of the two seconds I would expect).

Steps to reproduce

  1. Run time gz log record -v4.
  2. Ctrl+C once the output indicates it has started recording.
  3. Observe the total time taken.

Output

$ time gz log record -v4
Schema file: /opt/homebrew/Cellar/gz-transport13/13.4.1_4/share/gz/gz-transport13/sql/0.1.0.sql
Started recording to [20250618_144323.tlog]
^CShutting down
Log Recorder finalizing log file. This might take some time...Done
gz log record -v4  0.07s user 0.09s system 0% cpu 16.922 total
profiler view showing what I described

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    Status

    Inbox

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions