Project

General

Profile

Actions

Bug #1244

closed

lttng clear hangs on empty and active session

Added by Francis Deslauriers about 4 years ago. Updated about 4 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Target version:
-
Start date:
03/09/2020
Due date:
% Done:

100%

Estimated time:

Description

Clearing an active session hangs when running lttng clear:

    lttng create adam_lupien
    lttng enable-event -a -u
    lttng start
    #no event
    lttng clear
    Waiting for clear of session "adam_lupien"...........
    .................................................^C

While debugging, I saw that the unlinkat() at src/common/compat/directory-handle.c:359 returns -1 and errno is set to 39 (Directory not empty).
I created a change to add a PERROR() call in this function: https://review.lttng.org/c/lttng-tools/+/3197

Here is the lttng-sessiond -vvv --verbose-consumer output of that command:

DEBUG1 - 10:29:43.825488427 [19947/19955]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 10:29:43.825574380 [19947/19955]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 10:29:43.825615533 [19947/19955]: Processing client command 13 (in process_client_msg() at client.c:714)
DEBUG1 - 10:29:43.825634931 [19947/19955]: Counting number of available session for UID 1000 GID 1000 (in lttng_sessions_count() at client.c:513)
DEBUG1 - 10:29:43.825667557 [19947/19955]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.c:3733)
DEBUG1 - 10:29:43.825696315 [19947/19955]: Sending response (size: 4412, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 10:29:43.825745115 [19947/19955]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 10:29:43.825763648 [19947/19955]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 10:29:43.826010549 [19947/19955]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 10:29:43.826132967 [19947/19955]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 10:29:43.826189590 [19947/19955]: Processing client command 50 (in process_client_msg() at client.c:714)
DEBUG1 - 10:29:43.826213531 [19947/19955]: Getting session natasha_carpentier by name (in process_client_msg() at client.c:811)
DEBUG2 - 10:29:43.826226841 [19947/19955]: Trying to find session by name natasha_carpentier (in session_find_by_name() at session.c:1000)
DEBUG1 - 10:29:43.826240395 [19947/19955]: Stopping all UST traces (in ust_app_stop_trace_all() at ust-app.c:4890)
DEBUG1 - 10:29:43.826251953 [19947/19955]: Flushing session buffers for all ust apps (in ust_app_flush_session() at ust-app.c:4584)
DEBUG1 - 10:29:43.826265479 [19947/19955]: lttng_trace_chunk_rename_path from  to .tmp_old_chunk (in lttng_trace_chunk_rename_path_no_lock() at trace-chunk.c:740)
DEBUG3 - 10:29:43.826278001 [19947/19955]: mkdirat() recursive fd = 63, path = .tmp_old_chunk, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat() at runas.c:1462)
DEBUG1 - 10:29:43.826296317 [19947/19955]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG1 - 10:29:43.826530407 [19947/19955]: Creating trace chunk: chunk_id = 1, creation time = 20200309-102943 (in lttng_trace_chunk_create() at trace-chunk.c:422)
DEBUG1 - 10:29:43.826554333 [19947/19955]: Chunk name set to "20200309T102943-0400-1" (in lttng_trace_chunk_create() at trace-chunk.c:452)
DEBUG1 - 10:29:43.826565814 [19947/19955]: Creating base output directory of session "natasha_carpentier" at /home/frdeso/lttng-traces/natasha_carpentier-20200309-102935 (in session_create_new_trace_chunk() at session.c:653)
DEBUG3 - 10:29:43.826578899 [19947/19955]: mkdirat() recursive fd = -100 (AT_FDCWD), path = /home/frdeso/lttng-traces/natasha_carpentier-20200309-102935, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat_recursive() at runas.c:1428)
DEBUG1 - 10:29:43.826597352 [19947/19955]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG3 - 10:29:43.826736410 [19947/19955]: mkdirat() recursive fd = 65, path = .tmp_new_chunk, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat() at runas.c:1462)
DEBUG1 - 10:29:43.826764493 [19947/19955]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG3 - 10:29:43.826894415 [19947/19955]: mkdirat() recursive fd = 66, path = ust, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat() at runas.c:1462)
DEBUG1 - 10:29:43.826914460 [19947/19955]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG1 - 10:29:43.827022992 [19947/19955]: Sending consumer create trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 1, creation_timestamp = 20200309T102943-0400 (in consumer_create_trace_chunk() at consumer.c:1914)
DEBUG1 - 10:29:43.827059218 [19968/19977]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3360)
DEBUG1 - 10:29:43.827124533 [19947/19955]: Sending trace chunk domain directory fd to consumer (in consumer_create_trace_chunk() at consumer.c:1925)
DEBUG1 - 10:29:43.827159506 [19968/19977]: Received trace chunk domain directory fd (32) (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:2084)
DEBUG1 - 10:29:43.827200467 [19968/19977]: Consumer create trace chunk command: relay_id = (none), session_id = 0, chunk_id = 1, chunk_override_name = (none), chunk_creation_timestamp = 20200309T102943-0400 (in lttng_consumer_create_trace_chunk() at consumer.c:4574)
DEBUG1 - 10:29:43.827224912 [19968/19977]: Creating trace chunk: chunk_id = 1, creation time = 20200309-102943 (in lttng_trace_chunk_create() at trace-chunk.c:422)
DEBUG1 - 10:29:43.827249055 [19968/19977]: Chunk name set to "20200309T102943-0400-1" (in lttng_trace_chunk_create() at trace-chunk.c:452)
DEBUG1 - 10:29:43.827295842 [19968/19977]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3376)
DEBUG1 - 10:29:43.827304698 [19947/19955]: Setting trace chunk close command to "delete" (in lttng_trace_chunk_set_close_command() at trace-chunk.c:1784)
DEBUG1 - 10:29:43.827321676 [19947/19955]: lttng_trace_chunk_rename_path from .tmp_new_chunk to  (in lttng_trace_chunk_rename_path_no_lock() at trace-chunk.c:740)
Error: Error removing subdirectory '.tmp_new_chunk' file when deleting chunk
DEBUG1 - 10:29:43.827376971 [19947/19955]: Trace chunk "delete" close command post-release (User) (in lttng_trace_chunk_delete_post_release_user() at trace-chunk.c:1647)
DEBUG1 - 10:29:43.827389605 [19947/19955]: Trace chunk "delete" close command post-release (Owner) (in lttng_trace_chunk_delete_post_release_owner() at trace-chunk.c:1682)
DEBUG1 - 10:29:43.827452980 [19947/19955]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 10:29:43.827466600 [19947/19955]: Accepting client command ... (in thread_manage_clients() at client.c:2223)

My lttng version:

lttng (LTTng Trace Control) 2.12.0-rc1 - (Ta) Meilleure - v2.12.0-rc1-30-g938bd4228

Actions #1

Updated by Jonathan Rajotte Julien about 4 years ago

  • Status changed from New to Feedback
Actions #2

Updated by Jonathan Rajotte Julien about 4 years ago

  • Status changed from Feedback to Resolved
  • % Done changed from 0 to 100
Actions

Also available in: Atom PDF