1 /*
2  * Copyright (C) 2021 Huawei Device Co., Ltd.
3  * Licensed under the Apache License, Version 2.0 (the "License");
4  * you may not use this file except in compliance with the License.
5  * You may obtain a copy of the License at
6  *
7  *     http://www.apache.org/licenses/LICENSE-2.0
8  *
9  * Unless required by applicable law or agreed to in writing, software
10  * distributed under the License is distributed on an "AS IS" BASIS,
11  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12  * See the License for the specific language governing permissions and
13  * limitations under the License.
14  */
15 
16 #include <unistd.h>
17 #include <sys/time.h>
18 #include <iostream>
19 #include <string>
20 #include <sstream>
21 #include <regex>
22 #include <chrono>
23 #include <securec.h>
24 #include <gtest/gtest.h>
25 #include "ipc_debug.h"
26 #include "hitrace/trace.h"
27 #include "ipc_skeleton.h"
28 #include "ipc_object_proxy.h"
29 #include "test_service_skeleton.h"
30 #include "test_service.h"
31 #include "ipc_test_helper.h"
32 #include "binder_connector.h"
33 #include "if_system_ability_manager.h"
34 #include "iservice_registry.h"
35 #include "system_ability_definition.h"
36 #include "log_tags.h"
37 
38 using namespace testing::ext;
39 using namespace OHOS;
40 using namespace OHOS::HiviewDFX;
41 
42 static constexpr HiLogLabel LOG_LABEL = { LOG_CORE, LOG_ID_TEST, "BinderTraceUnitTest" };
43 
44 class BinderTraceTest : public testing::Test {
45 public:
46     static void SetUpTestCase(void);
47     static void TearDownTestCase(void);
48 
49 private:
50     static IPCTestHelper *g_helper;
51 };
52 IPCTestHelper *BinderTraceTest::g_helper = nullptr;
SetUpTestCase()53 void BinderTraceTest::SetUpTestCase()
54 {
55     if (g_helper == nullptr) {
56         g_helper = new IPCTestHelper();
57         bool res = g_helper->PrepareTestSuite();
58         ASSERT_TRUE(res);
59     }
60 }
61 
TearDownTestCase()62 void BinderTraceTest::TearDownTestCase()
63 {
64     if (g_helper != nullptr) {
65         bool res = g_helper->TearDownTestSuite();
66         ASSERT_TRUE(res);
67         delete g_helper;
68         g_helper = nullptr;
69     }
70 }
71 
HitraceLongToString(unsigned long data)72 static std::string HitraceLongToString(unsigned long data)
73 {
74     std::string result;
75     constexpr int BUFFER_SIZE = 21;
76     char str[BUFFER_SIZE] = {0};
77 
78     if (sprintf_s(str, sizeof(str), "%lu", data) <= 0) {
79         return result;
80     }
81 
82     result = str;
83     return result;
84 }
85 
BinderTraceGetRemainLog(const std::string & tag)86 static std::string BinderTraceGetRemainLog(const std::string &tag)
87 {
88     std::string logMsgs;
89     std::string remainLogMsgs;
90     constexpr int BUFFER_SIZE = 1024;
91     FILE *fp = popen("/system/bin/hilog -x -z 4096", "re");
92     bool findTag = false;
93 
94     if (fp != nullptr) {
95         char buf[BUFFER_SIZE] = {0};
96         size_t n;
97         n = fread(buf, 1, sizeof(buf), fp);
98         while (n > 0) {
99             logMsgs.append(buf, n);
100             n = fread(buf, 1, sizeof(buf), fp);
101         }
102         pclose(fp);
103     } else {
104         return remainLogMsgs;
105     }
106 
107     std::stringstream ss(logMsgs);
108     std::string str;
109     while (!ss.eof()) {
110         getline(ss, str);
111 
112         if (findTag == false && str.find(tag) != std::string::npos) {
113             findTag = true;
114         }
115 
116         if (findTag == true) {
117             remainLogMsgs.append(str);
118         }
119     }
120 
121     return remainLogMsgs;
122 }
BinderTraceCheckLog(const std::string & remainLogMsgs,const std::string & checkItem,const std::string & chainId)123 static int BinderTraceCheckLog(const std::string &remainLogMsgs, const std::string &checkItem,
124     const std::string &chainId)
125 {
126     std::stringstream rss(remainLogMsgs);
127     std::string str;
128     std::regex re(checkItem);
129 
130     while (!rss.eof()) {
131         getline(rss, str);
132         if (std::regex_search(str, re) == true && str.find(chainId) != std::string::npos) {
133             return 1;
134         }
135     }
136 
137     return 0;
138 }
139 
PrintTagLog(const std::string & tag)140 static std::string PrintTagLog(const std::string &tag)
141 {
142     struct timeval tv = {};
143     constexpr int SEC_TO_USEC = 1000000;
144     gettimeofday(&tv, nullptr);
145     long long timeStamp = tv.tv_sec * SEC_TO_USEC + tv.tv_usec;
146     std::string strTimeStamp;
147     std::stringstream ss;
148     ss << timeStamp;
149     ss >> strTimeStamp;
150     std::string logTag = strTimeStamp + tag;
151     HiLog::Info(LOG_LABEL, "%s\n", logTag.c_str());
152     return logTag;
153 }
154 
155 HWTEST_F(BinderTraceTest, Sync001, TestSize.Level1)
156 {
157     HiTraceId getId = HiTraceChain::GetId();
158     EXPECT_EQ(0, getId.IsValid());
159     HiTraceId traceId = HiTraceChain::Begin("ipc hitrace", 0);
160     std::string chainId = HitraceLongToString(traceId.GetChainId());
161     EXPECT_NE(0UL, chainId.size());
162     IPCTestHelper helper;
163     bool res = helper.StartTestApp(IPCTestHelper::IPC_TEST_SERVER);
164     ASSERT_TRUE(res);
165 
166     auto saMgr = SystemAbilityManagerClient::GetInstance().GetSystemAbilityManager();
167 
168     ASSERT_TRUE(saMgr != nullptr);
169 
170     sptr<IRemoteObject> service = saMgr->GetSystemAbility(IPC_TEST_SERVICE);
171     sptr<ITestService> testService = iface_cast<ITestService>(service);
172 
173     ASSERT_TRUE(testService != nullptr);
174     HiLog::Info(LOG_LABEL, "Get test.service OK\n");
175     std::string logTag = PrintTagLog(":BinderTraceTest_Sync001");
176 
177     if (service->IsProxyObject()) {
178         HiLog::Info(LOG_LABEL, "Got Proxy node\n");
179         TestServiceProxy *proxy = static_cast<TestServiceProxy *>(testService.GetRefPtr());
180         int reply = 0;
181         int ret = proxy->TestSyncTransaction(2019, reply);
182         EXPECT_EQ(ret, NO_ERROR);
183         EXPECT_EQ(reply, 9102);
184     } else {
185         HiLog::Info(LOG_LABEL, "Got Stub node\n");
186     }
187 
188     getId = HiTraceChain::GetId();
189     EXPECT_EQ(1, getId.IsValid());
190     HiTraceChain::End(traceId);
191     getId = HiTraceChain::GetId();
192     EXPECT_EQ(0, getId.IsValid());
193     std::string remainLogMsgs = BinderTraceGetRemainLog(logTag);
194     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_CS", chainId));
195     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_SR", chainId));
196     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_SS", chainId));
197     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_CR", chainId));
198 }
199 
200 HWTEST_F(BinderTraceTest, Sync002, TestSize.Level1)
201 {
202     const std::string HITRACE_TP_CS_LOG =
203         "\\[[a-f0-9]{1,16}, 0, 0\\] <HITRACE_TP_CS,chain=[0-9a-f]{1,16},span=[0-9a-f]{1,16},pspan=";
204     const std::string HITRACE_TP_SR_LOG =
205         "\\[[a-f0-9]{1,16}, [a-f0-9]{1,16}, 0\\] <HITRACE_TP_SR,chain=[0-9a-f]{1,16},span=[0-9a-f]{1,16},pspan=";
206     const std::string HITRACE_TP_SS_LOG =
207         "\\[[a-f0-9]{1,16}, [a-f0-9]{1,16}, 0\\] <HITRACE_TP_SS,chain=[0-9a-f]{1,16},span=[0-9a-f]{1,16},pspan=";
208     const std::string HITRACE_TP_CR_LOG =
209         "\\[[a-f0-9]{1,16}, 0, 0\\] <HITRACE_TP_CR,chain=[0-9a-f]{1,16},span=[0-9a-f]{1,16},pspan=";
210     HiTraceId getId = HiTraceChain::GetId();
211     EXPECT_EQ(0, getId.IsValid());
212     HiTraceId traceId = HiTraceChain::Begin("ipc hitrace", HITRACE_FLAG_TP_INFO);
213     std::string chainId = HitraceLongToString(traceId.GetChainId());
214     EXPECT_NE(0UL, chainId.size());
215     IPCTestHelper helper;
216     bool res = helper.StartTestApp(IPCTestHelper::IPC_TEST_SERVER);
217     ASSERT_TRUE(res);
218 
219     auto saMgr = SystemAbilityManagerClient::GetInstance().GetSystemAbilityManager();
220 
221     ASSERT_TRUE(saMgr != nullptr);
222 
223     sptr<IRemoteObject> service = saMgr->GetSystemAbility(IPC_TEST_SERVICE);
224     sptr<ITestService> testService = iface_cast<ITestService>(service);
225 
226     ASSERT_TRUE(testService != nullptr);
227     HiLog::Info(LOG_LABEL, "Get test.service OK\n");
228     std::string logTag = PrintTagLog(":BinderTraceTest_Sync002");
229 
230     if (service->IsProxyObject()) {
231         HiLog::Info(LOG_LABEL, "Got Proxy node\n");
232         TestServiceProxy *proxy = static_cast<TestServiceProxy *>(testService.GetRefPtr());
233         int reply = 0;
234         int ret = proxy->TestSyncTransaction(2019, reply);
235         EXPECT_EQ(ret, NO_ERROR);
236         EXPECT_EQ(reply, 9102);
237     } else {
238         HiLog::Info(LOG_LABEL, "Got Stub node\n");
239     }
240 
241     getId = HiTraceChain::GetId();
242     EXPECT_EQ(1, getId.IsValid());
243     HiTraceChain::End(traceId);
244     getId = HiTraceChain::GetId();
245     EXPECT_EQ(0, getId.IsValid());
246 }
247 
248 HWTEST_F(BinderTraceTest, Sync003, TestSize.Level1)
249 {
250     const std::string HITRACE_TP_CS_LOG = "\\[[a-f0-9]{1,16}\\] <HITRACE_TP_CS,chain=[0-9a-f]{1,16},span=0,pspan=";
251     const std::string HITRACE_TP_SR_LOG = "\\[[a-f0-9]{1,16}\\] <HITRACE_TP_SR,chain=[0-9a-f]{1,16},span=0,pspan=";
252     const std::string HITRACE_TP_SS_LOG = "\\[[a-f0-9]{1,16}\\] <HITRACE_TP_SS,chain=[0-9a-f]{1,16},span=0,pspan=";
253     const std::string HITRACE_TP_CR_LOG = "\\[[a-f0-9]{1,16}\\] <HITRACE_TP_CR,chain=[0-9a-f]{1,16},span=0,pspan=";
254     HiTraceId getId = HiTraceChain::GetId();
255     EXPECT_EQ(0, getId.IsValid());
256     HiTraceId traceId = HiTraceChain::Begin("ipc hitrace", HITRACE_FLAG_TP_INFO | HITRACE_FLAG_DONOT_CREATE_SPAN);
257     std::string chainId = HitraceLongToString(traceId.GetChainId());
258     EXPECT_NE(0UL, chainId.size());
259     IPCTestHelper helper;
260     bool res = helper.StartTestApp(IPCTestHelper::IPC_TEST_SERVER);
261     ASSERT_TRUE(res);
262 
263     auto saMgr = SystemAbilityManagerClient::GetInstance().GetSystemAbilityManager();
264     ASSERT_TRUE(saMgr != nullptr);
265 
266     sptr<IRemoteObject> service = saMgr->GetSystemAbility(IPC_TEST_SERVICE);
267     sptr<ITestService> testService = iface_cast<ITestService>(service);
268     ASSERT_TRUE(testService != nullptr);
269 
270     HiLog::Info(LOG_LABEL, "Get test.service OK\n");
271     std::string logTag = PrintTagLog(":BinderTraceTest_Sync003");
272     if (service->IsProxyObject()) {
273         HiLog::Info(LOG_LABEL, "Got Proxy node\n");
274         TestServiceProxy *proxy = static_cast<TestServiceProxy *>(testService.GetRefPtr());
275         int reply = 0;
276         int ret = proxy->TestSyncTransaction(2019, reply);
277         EXPECT_EQ(ret, NO_ERROR);
278         EXPECT_EQ(reply, 9102);
279     } else {
280         HiLog::Info(LOG_LABEL, "Got Stub node\n");
281     }
282 
283     getId = HiTraceChain::GetId();
284     EXPECT_EQ(1, getId.IsValid());
285     HiTraceChain::End(traceId);
286     getId = HiTraceChain::GetId();
287     EXPECT_EQ(0, getId.IsValid());
288 }
289 
290 HWTEST_F(BinderTraceTest, Async001, TestSize.Level1)
291 {
292     HiTraceId getId = HiTraceChain::GetId();
293     EXPECT_EQ(0, getId.IsValid());
294     HiTraceId traceId = HiTraceChain::Begin("ipc hitrace", HITRACE_FLAG_INCLUDE_ASYNC);
295     std::string chainId = HitraceLongToString(traceId.GetChainId());
296     EXPECT_NE(0UL, chainId.size());
297     IPCTestHelper helper;
298     bool res = helper.StartTestApp(IPCTestHelper::IPC_TEST_SERVER);
299     ASSERT_TRUE(res);
300 
301     auto saMgr = SystemAbilityManagerClient::GetInstance().GetSystemAbilityManager();
302 
303     ASSERT_TRUE(saMgr != nullptr);
304 
305     sptr<IRemoteObject> service = saMgr->GetSystemAbility(IPC_TEST_SERVICE);
306     sptr<ITestService> testService = iface_cast<ITestService>(service);
307 
308     ASSERT_TRUE(testService != nullptr);
309     HiLog::Info(LOG_LABEL, "Get test.service OK\n");
310     std::string logTag = PrintTagLog(":BinderTraceTest_Async001");
311 
312     if (service->IsProxyObject()) {
313         HiLog::Info(LOG_LABEL, "Got Proxy node\n");
314         TestServiceProxy *proxy = static_cast<TestServiceProxy *>(testService.GetRefPtr());
315         int ret = proxy->TestAsyncTransaction(2019);
316         EXPECT_EQ(ret, ERR_NONE);
317     } else {
318         HiLog::Info(LOG_LABEL, "Got Stub node\n");
319     }
320 
321     getId = HiTraceChain::GetId();
322     EXPECT_EQ(1, getId.IsValid());
323     HiTraceChain::End(traceId);
324     getId = HiTraceChain::GetId();
325     EXPECT_EQ(0, getId.IsValid());
326     std::string remainLogMsgs = BinderTraceGetRemainLog(logTag);
327     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_CS", chainId));
328     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_SR", chainId));
329     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_SS", chainId));
330     EXPECT_EQ(0, BinderTraceCheckLog(remainLogMsgs, "HITRACE_TP_CR", chainId));
331 }
332 
333 HWTEST_F(BinderTraceTest, Async002, TestSize.Level1)
334 {
335     const std::string HITRACE_TP_CS_LOG =
336         "\\[[a-f0-9]{1,16}, 0, 0\\] <HITRACE_TP_CS,chain=[0-9a-f]{1,16},span=[0-9a-f]{1,16},pspan=";
337     const std::string HITRACE_TP_SR_LOG =
338         "\\[[a-f0-9]{1,16}, [a-f0-9]{1,16}, 0\\] <HITRACE_TP_SR,chain=[0-9a-f]{1,16},span=[0-9a-f]{1,16},pspan=";
339     HiTraceId getId = HiTraceChain::GetId();
340     EXPECT_EQ(0, getId.IsValid());
341     HiTraceId traceId = HiTraceChain::Begin("ipc hitrace", HITRACE_FLAG_TP_INFO | HITRACE_FLAG_INCLUDE_ASYNC);
342     std::string chainId = HitraceLongToString(traceId.GetChainId());
343     EXPECT_NE(0UL, chainId.size());
344     IPCTestHelper helper;
345     bool res = helper.StartTestApp(IPCTestHelper::IPC_TEST_SERVER);
346     ASSERT_TRUE(res);
347 
348     auto saMgr = SystemAbilityManagerClient::GetInstance().GetSystemAbilityManager();
349 
350     ASSERT_TRUE(saMgr != nullptr);
351 
352     sptr<IRemoteObject> service = saMgr->GetSystemAbility(IPC_TEST_SERVICE);
353     sptr<ITestService> testService = iface_cast<ITestService>(service);
354 
355     ASSERT_TRUE(testService != nullptr);
356     HiLog::Info(LOG_LABEL, "Get test.service OK\n");
357     std::string logTag = PrintTagLog(":BinderTraceTest_Async002");
358 
359     if (service->IsProxyObject()) {
360         HiLog::Info(LOG_LABEL, "Got Proxy node\n");
361         TestServiceProxy *proxy = static_cast<TestServiceProxy *>(testService.GetRefPtr());
362         int ret = proxy->TestAsyncTransaction(2019, 1);
363         EXPECT_EQ(ret, ERR_NONE);
364     } else {
365         HiLog::Info(LOG_LABEL, "Got Stub node\n");
366     }
367 
368     getId = HiTraceChain::GetId();
369     EXPECT_EQ(1, getId.IsValid());
370     HiTraceChain::End(traceId);
371     getId = HiTraceChain::GetId();
372     EXPECT_EQ(0, getId.IsValid());
373 }
374 
375 HWTEST_F(BinderTraceTest, Async003, TestSize.Level1)
376 {
377     const std::string HITRACE_TP_CS_LOG = "\\[[a-f0-9]{1,16}\\] <HITRACE_TP_CS,chain=[0-9a-f]{1,16},span=0,pspan=";
378     const std::string HITRACE_TP_SR_LOG = "\\[[a-f0-9]{1,16}\\] <HITRACE_TP_SR,chain=[0-9a-f]{1,16},span=0,pspan=";
379     HiTraceId getId = HiTraceChain::GetId();
380     EXPECT_EQ(0, getId.IsValid());
381     HiTraceId traceId = HiTraceChain::Begin("ipc hitrace",
382         HITRACE_FLAG_TP_INFO | HITRACE_FLAG_INCLUDE_ASYNC | HITRACE_FLAG_DONOT_CREATE_SPAN);
383     std::string chainId = HitraceLongToString(traceId.GetChainId());
384     EXPECT_NE(0UL, chainId.size());
385     IPCTestHelper helper;
386     bool res = helper.StartTestApp(IPCTestHelper::IPC_TEST_SERVER);
387     ASSERT_TRUE(res);
388 
389     auto saMgr = SystemAbilityManagerClient::GetInstance().GetSystemAbilityManager();
390 
391     ASSERT_TRUE(saMgr != nullptr);
392 
393     sptr<IRemoteObject> service = saMgr->GetSystemAbility(IPC_TEST_SERVICE);
394     sptr<ITestService> testService = iface_cast<ITestService>(service);
395 
396     ASSERT_TRUE(testService != nullptr);
397     HiLog::Info(LOG_LABEL, "Get test.service OK\n");
398     std::string logTag = PrintTagLog(":BinderTraceTest_Async003");
399 
400     if (service->IsProxyObject()) {
401         HiLog::Info(LOG_LABEL, "Got Proxy node\n");
402         TestServiceProxy *proxy = static_cast<TestServiceProxy *>(testService.GetRefPtr());
403         int ret = proxy->TestAsyncTransaction(2019, 1);
404         EXPECT_EQ(ret, ERR_NONE);
405     } else {
406         HiLog::Info(LOG_LABEL, "Got Stub node\n");
407     }
408 
409     getId = HiTraceChain::GetId();
410     EXPECT_EQ(1, getId.IsValid());
411     HiTraceChain::End(traceId);
412     getId = HiTraceChain::GetId();
413     EXPECT_EQ(0, getId.IsValid());
414 }
415