Support printing a thread debug log via http request

CHANGELOG.md

@@ -3,6 +3,10 @@
 1. All notable changes to this project will be documented in this file.
 2. Records in this file are not identical to the title of their Pull Requests. A detailed description is necessary for understanding what changes are and why they are made.
 
+## UnReleased
+### New features
+- Add a new tool: A debug tool for Trace Profiling is provided for developers to troubleshoot problems.([#363](https://github.com/CloudDectective-Harmonycloud/kindling/pull/363))
+
 ## v0.5.0 - 2022-11-02
 ### New features
 - Add a new feature: Trace Profiling. See more details about it on our [website](http://kindling.harmonycloud.cn). ([#335](https://github.com/CloudDectective-Harmonycloud/kindling/pull/335))

collector/pkg/component/controller/controller.go

@@ -26,6 +26,9 @@ type ControlRequest struct {
 	// start / stop
 	Operation string
 
+	Pid int
+	Tid int
+
 	// json Options
 	Options *json.RawMessage
 }

collector/pkg/component/controller/profile_module.go

@@ -1,5 +1,14 @@
 package controller
 
+/*
+#cgo LDFLAGS: -L ./ -lkindling  -lstdc++ -ldl
+#cgo CFLAGS: -I .
+#include <stdlib.h>
+#include <stdint.h>
+#include <stdio.h>
+#include "../receiver/cgoreceiver/cgo_func.h"
+*/
+import "C"
 import (
 	"encoding/json"
 	"errors"
@@ -79,6 +88,16 @@ func (p *Profile) GetModuleKey() string {
 	return p.Name()
 }
 
+func startDebug(pid int, tid int) error {
+	C.startProfileDebug(C.int(pid), C.int(tid))
+	return nil
+}
+
+func stopDebug() error {
+	C.stopProfileDebug()
+	return nil
+}
+
 func (p *Profile) HandRequest(req *ControlRequest) *ControlResponse {
 	switch req.Operation {
 	case "start":
@@ -116,6 +135,24 @@ func (p *Profile) HandRequest(req *ControlRequest) *ControlResponse {
 			Code: NoError,
 			Msg:  status,
 		}
+	case "start_debug":
+		if err := startDebug(req.Pid, req.Tid); err != nil {
+			return &ControlResponse{
+				Code: StopWithError,
+				Msg:  err.Error(),
+			}
+		}
+		return &ControlResponse{
+			Code: NoError,
+			Msg:  "start debug success",
+		}
+	case "stop_debug":
+		stopDebug()
+		return &ControlResponse{
+			Code: NoError,
+			Msg:  "stop debug success",
+		}
+
 	default:
 		return &ControlResponse{
 			Code: NoOperation,

collector/pkg/component/receiver/cgoreceiver/cgo_func.h

@@ -13,6 +13,8 @@ int getKindlingEvent(void **kindlingEvent);
 int subEventForGo(char* eventName, char* category);
 int startProfile();
 int stopProfile();
+void startProfileDebug(int pid, int tid);
+void stopProfileDebug();
 #ifdef __cplusplus
 }
 

probe/src/cgo/cgo_func.cpp

@@ -24,4 +24,12 @@ int startProfile() {
 }
 int stopProfile() {
     return stop_profile();
+}
+
+void startProfileDebug(int pid, int tid) {
+    start_profile_debug(pid, tid);
+}
+
+void stopProfileDebug() {
+    stop_profile_debug();
 }

probe/src/cgo/cgo_func.h

@@ -13,6 +13,8 @@ int getKindlingEvent(void **kindlingEvent);
 void subEventForGo(char* eventName, char* category);
 int startProfile();
 int stopProfile();
+void startProfileDebug(int pid, int tid);
+void stopProfileDebug();
 #ifdef __cplusplus
 }
 #endif

probe/src/cgo/kindling.cpp

@@ -6,13 +6,15 @@
 #include "scap_open_exception.h"
 #include "sinsp_capture_interrupt_exception.h"
 #include <iostream>
+#include <fstream>
 #include <cstdlib>
 #include <thread>
 
 #include "converter/cpu_converter.h"
 
 
 cpu_converter *cpuConverter;
+fstream debug_file_log;
 map<uint64_t, char *> ptid_comm;
 static sinsp *inspector = nullptr;
 sinsp_evt_formatter *formatter = nullptr;
@@ -25,6 +27,9 @@ vector<QObject *> qls;
 
 bool is_start_profile = false;
 bool all_attach = true;
+bool is_profile_debug = false;
+int64_t debug_pid = 0;
+int64_t debug_tid = 0;
 char *traceId = new char[128];
 char *isEnter = new char[16];
 char *start_time_char = new char[32];
@@ -179,7 +184,9 @@ int getEvent(void **pp_kindling_event)
 	uint16_t ev_type = ev->get_type();
 
     print_event(ev);
-
+    if(ev_type!=PPME_CPU_ANALYSIS_E && is_profile_debug && threadInfo->m_tid == debug_tid && threadInfo->m_pid == debug_pid){
+        print_profile_debug_info(ev);
+    }
     kindling_event_t_for_go *p_kindling_event;
     init_kindling_event(p_kindling_event, pp_kindling_event);
 
@@ -229,7 +236,7 @@ int getEvent(void **pp_kindling_event)
 		}
 
     	strcpy(p_kindling_event->context.tinfo.comm, tmp_comm);
-        return cpuConverter->convert(p_kindling_event, ev, qls);
+        return cpuConverter->convert(p_kindling_event, ev, qls, is_profile_debug, debug_pid, debug_tid);
 	}
 
     if(event_filters[ev_type][kindling_category] == 0)
@@ -885,4 +892,31 @@ int stop_profile() {
     inspector->unset_eventmask(PPME_CPU_ANALYSIS_E);
 
     return 0;
+}
+
+void start_profile_debug(int64_t pid, int64_t tid) {
+    is_profile_debug = true;
+    debug_pid = pid;
+    debug_tid = tid;
+}
+
+void stop_profile_debug() {
+    is_profile_debug = false;
+    debug_pid = 0;
+    debug_tid = 0;
+}
+
+void print_profile_debug_info(sinsp_evt *sevt){
+    if (!debug_file_log.is_open()){
+        debug_file_log.open("profile_debug.log",  ios::app|ios::out);
+    }
+    string line;
+    if (formatter->tostring(sevt, &line)) {
+        if (debug_file_log.is_open())
+        {
+            debug_file_log << sevt->get_ts() << "  ";
+            debug_file_log << line;
+            debug_file_log << "\n";
+        }
+    }
 }

probe/src/cgo/kindling.h

@@ -36,6 +36,12 @@ int start_profile();
 
 int stop_profile();
 
+void start_profile_debug(int64_t pid, int64_t tid);
+
+void stop_profile_debug();
+
+void print_profile_debug_info(sinsp_evt *sevt);
+
 void attach_pid(char* pid, bool is_new_start, bool is_attach, bool is_all_attach, bool is_ps);
 
 uint16_t get_protocol(scap_l4_proto proto);

probe/src/converter/cpu_converter.cpp

@@ -5,7 +5,10 @@
 #include "cpu_converter.h"
 #include <vector>
 #include "iostream"
+#include <fstream>
 
+
+fstream debug_file;
 using namespace std;
 
 cpu_converter::cpu_converter(sinsp *inspector) : m_inspector(inspector) {
@@ -16,11 +19,11 @@ cpu_converter::~cpu_converter() {
 }
 
 
-int cpu_converter::convert(kindling_event_t_for_go *p_kindling_event, sinsp_evt *cpu_evt, vector<QObject *> qls) {
+int cpu_converter::convert(kindling_event_t_for_go *p_kindling_event, sinsp_evt *cpu_evt, vector<QObject *> qls, bool is_profile_debug, int64_t debug_pid, int64_t debug_tid) {
     // convert
     init_kindling_event(p_kindling_event, cpu_evt);
     add_threadinfo(p_kindling_event, cpu_evt);
-    add_cpu_data(p_kindling_event, cpu_evt, qls);
+    add_cpu_data(p_kindling_event, cpu_evt, qls, is_profile_debug, debug_pid, debug_tid);
     return 1;
 }
 
@@ -43,7 +46,7 @@ int cpu_converter::add_threadinfo(kindling_event_t_for_go *p_kindling_event, sin
 	return 0;
 }
 
-int cpu_converter::add_cpu_data(kindling_event_t_for_go *p_kindling_event, sinsp_evt *sevt, vector<QObject *> qls) {
+int cpu_converter::add_cpu_data(kindling_event_t_for_go *p_kindling_event, sinsp_evt *sevt, vector<QObject *> qls, bool is_profile_debug, int64_t debug_pid, int64_t debug_tid) {
     uint64_t start_time = *reinterpret_cast<uint64_t *> (sevt->get_param_value_raw("start_ts")->m_val);
     uint64_t end_time = *reinterpret_cast<uint64_t *> (sevt->get_param_value_raw("end_ts")->m_val);
     uint32_t cnt = *reinterpret_cast<uint32_t *> (sevt->get_param_value_raw("cnt")->m_val);
@@ -185,5 +188,23 @@ int cpu_converter::add_cpu_data(kindling_event_t_for_go *p_kindling_event, sinsp
     p_kindling_event->userAttributes[userAttNumber].len = info.length();
     userAttNumber++;
     p_kindling_event->paramsNumber = userAttNumber;
+
+    if(is_profile_debug && s_tinfo->m_tid == debug_tid && s_tinfo->m_pid == debug_pid){
+        if (!debug_file.is_open())
+        {
+            debug_file.open("profile_debug_cpu.log", ios::app|ios::out);
+        }else {
+            for(int i= 0;i<on_time.size();i++){
+                string debug_info = to_string(on_time[i].first) + "  -  " + to_string(on_time[i].second) + "on, " + " onnumber: " + to_string(i+1) +"oninfo:"+on_info;
+                debug_file << debug_info<<"\n";
+            }
+            for(int i= 0;i<off_time.size();i++){
+                string debug_info = to_string(off_time[i].first) + "  -  " + to_string(off_time[i].second) + "off, " + " offnumber: " + to_string(i+1) +"offinfo:"+info;
+                debug_file << debug_info<<"\n";
+            }
+
+        }
+    }
+
     return 0;
 }

probe/src/converter/cpu_converter.h

@@ -4,6 +4,7 @@
 #include <map>
 #include "sinsp.h"
 #include "cgo/kindling.h"
+
 class cpu_data {
 public:
     uint64_t start_time;
@@ -22,15 +23,15 @@ class cpu_converter
     cpu_converter(sinsp *inspector);
     ~cpu_converter();
 
-    int convert(kindling_event_t_for_go *p_kindling_event, sinsp_evt *evt, vector<QObject *> qls);
+    int convert(kindling_event_t_for_go *p_kindling_event, sinsp_evt *cpu_evt, vector<QObject *> qls, bool is_profile_debug, int64_t debug_pid, int64_t debug_tid);
 
     bool Cache(sinsp_evt *evt);
 private:
     int init_kindling_event(kindling_event_t_for_go *p_kindling_event, sinsp_evt *sevt);
 
     int add_threadinfo(kindling_event_t_for_go *p_kindling_event, sinsp_evt *sevt);
 
-    int add_cpu_data(kindling_event_t_for_go *p_kindling_event, sinsp_evt *sevt, vector<QObject *> qls);
+    int add_cpu_data(kindling_event_t_for_go *p_kindling_event, sinsp_evt *sevt, vector<QObject *> qls, bool is_profile_debug, int64_t debug_pid, int64_t debug_tid);
 
     int32_t set_boot_time(uint64_t *boot_time);