Support printing a thread debug log via http request (#363)

Signed-off-by: jundizhou <jundizhou@harmonycloud.cn>
KindlingProject · Nov 22, 2022 · 3396dc6 · 3396dc6
1 parent 2073a05
commit 3396dc6
Show file tree

Hide file tree

Showing 10 changed files with 125 additions and 7 deletions.
diff --git a/CHANGELOG.md b/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))

diff --git a/collector/pkg/component/controller/controller.go b/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
 }

diff --git a/collector/pkg/component/controller/profile_module.go b/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,

diff --git a/collector/pkg/component/receiver/cgoreceiver/cgo_func.h b/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
 }
 

diff --git a/probe/src/cgo/cgo_func.cpp b/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();
 }
diff --git a/probe/src/cgo/cgo_func.h b/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

diff --git a/probe/src/cgo/kindling.cpp b/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";
+ }
+ }
 }
diff --git a/probe/src/cgo/kindling.h b/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);

diff --git a/probe/src/converter/cpu_converter.cpp b/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;
 }
diff --git a/probe/src/converter/cpu_converter.h b/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);