65.9K
CodeProject 正在变化。 阅读更多。
Home

Strus 的方法调用跟踪。

starIconstarIconstarIconstarIcon
emptyStarIcon
starIcon

4.11/5 (2投票s)

2016年5月4日

MIT

6分钟阅读

viewsIcon

12607

downloadIcon

79

本文介绍了如何在 Strus 搜索引擎库项目的上下文中,为了调试、内省和统计分析而生成方法调用跟踪。

目标

对于 Java 开发者来说,使用方法调用跟踪作为开发工具是相当熟悉的。调用跟踪可以帮助您了解软件在执行特定任务时做了什么。它们还可以帮助您查找 bug、崩溃、死循环等。除了查找错误,它们还可以通过计算特定事件来帮助您统计分析行为。调用跟踪还能使软件透明化。这对于像Strus这样用户群体仍然非常小的项目尤其重要。透明度可以在其他人的经验几乎无法提供的情况下,为软件建立信任。

本文的目的是向您展示如何在Strus中创建方法调用跟踪。

背景

Strus 是一套用于构建搜索引擎的库和工具。它被分成几个小型项目(目前有 8 个),其中一个名为 strusTrace。它实现了方法调用跟踪的日志记录。

引言

C++ 作为编译型语言,不像 Java 那样有原生的跟踪支持。跟踪是您希望解决的一个经典问题,就像 面向切面编程一样。如何将面向切面编程引入软件在很大程度上取决于对其组件施加的规则。为了在 Strus 中实现跟踪作为一项面向切面编程,使用了Strus的以下两个特性:

  1. 在 Strus 中,每个接口都是一个 纯抽象类。这使得创建可以包装每次方法调用以及任何类访问的代理类成为可能。代理可以在幕后做其他事情(例如记录被调用的内容)的同时,将访问重定向到实际实现。
  2. 实现接口的所有对象要么是通过接口方法调用创建,要么是通过一个“根”对象创建。这种模式有助于控制对象的创建,并允许用代理实例包装每个创建的对象。

项目 strusTrace 使用了一些代码生成技术,为每个 strusstrusAnalyzer 接口类实现代理。最后,根对象(对象构建器接口)被一个代理实现包装。

使用调用跟踪

调用跟踪日志记录通过一个用分号(';')分隔的配置变量赋值的字符串来配置。其中一个变量是使用配置变量'log'指定的跟踪日志记录器的标识符。一些跟踪日志记录器是 strusTrace 的一部分。如果标准日志记录器不够用,您可以自己定义一个并将其作为 strus 模块加载。以下是预定义的标准跟踪日志记录器:

dump

将所有调用的方法立即记录到文件或 stdout。此日志记录器可用于分析崩溃或死循环的情况。示例

log=dump;file=stdout

将所有调用的方法和方法终止事件打印到 stdout

json

以 JSON 格式构建方法调用的依赖树,并将此树写入文件或 stdout。这是一个允许您在已终止的Strus运行的调用树中导航的日志记录器。示例

log=json;file=tree.json

将方法调用树作为 JSON 树打印到文件 tree.json

计数

计算指定类的特定方法的总调用次数。您可以将总调用次数打印到文件或 stdout,或者按实现指定接口的对象分组的调用次数。示例

log=count;groupby=PostingIterator;count=DatabaseCursor/seekUpperBound;file=stdout

计算 PostingIteratorInterface 实现的任何后代在 DatabaseCursorInterface 实现的 seekUpperBound 方法的调用次数。它输出一个数字对列表,其中包含 PostingIteratorInterface 实现的对象 ID,以及在该对象上下文中计数的 seekUpperBound 调用次数。

breakpoint

当方法被调用且时间计数器达到指定值时,调用函数 strus_breakpoint。此方法可用于在方法调用跟踪中的定义事件处设置调试器断点。示例

log=breakpoint;call=125821

当方法计数器为 125821 时,调用函数 strus_breakpoint。这允许您使用 strus 调用一个程序,并在调试器中暂停执行,在调用跟踪中的特定事件处设置的断点处停止。

语言绑定中的调用跟踪

要在语言绑定中使用调用跟踪,您必须在调用 Strus 上下文构造函数时,附加一个 string 参数,指定调用跟踪配置。跟踪不能在 RPC 客户端模式下使用(这在 RPC 客户端中也没有意义)。要在 RPC 上下文中进行跟踪,您可以启动配置了调用跟踪的 RPC 服务器。以下是一些示例构造函数调用:

Java

Context ctx = new Context( 0, "log=dump;file=stdout");

PHP

$ctx = new StrusContext( 0, "log=dump;file=dump.txt");

Python

ctx = strus.Context( 0, "log=json;file=tree.json" )

命令行工具的调用跟踪

Strus 命令行工具,例如 strusUtilities 项目中实现的程序和 strusRpc 项目中实现的 RPC 服务器,可以通过选项 -T--trace 启动,后面跟着 strus 跟踪配置。

以下 strusCreate 的示例调用会生成一个 JSON 调用树并将其打印到文件 tree.json

strusCreate -T "log=json;file=out.json" -s "path=storage; metadata=doclen UINT16"

然后我们将得到:

storage successfully created.

现在让我们看一下打印出的文件 out.json

{
"calls":[
  {
  "time":1,
  "object":1,
  "class":"StorageObjectBuilder",
  "method":"getDatabase",
  "parameter": ["Database<2>", "path=storage; metadata=doclen UINT16"]
  },
  {
  "time":2,
  "object":1,
  "class":"StorageObjectBuilder",
  "method":"getStorage",
  "parameter": ["Storage<3>"]
  },
  {
  "time":3,
  "object":3,
  "class":"Storage",
  "method":"getConfigParameters",
  "parameter": [[
    "cachedterms"], "CreateClient"]
  },
  {
  "time":4,
  "object":2,
  "class":"Database",
  "method":"getConfigParameters",
  "parameter": [[
    "path",
    "cache",
    "compression",
    "max_open_files",
    "write_buffer_size",
    "block_size"], "CreateClient"]
  },
  {
  "time":5,
  "object":2,
  "class":"Database",
  "method":"createDatabase",
  "parameter": [true, "path=storage; metadata=doclen UINT16"]
  },
  {
  "time":6,
  "object":2,
  "class":"Database",
  "method":"createClient",
  "parameter": ["DatabaseClient<4>", "path=storage; metadata=doclen UINT16"]
  },
  {
  "time":7,
  "object":3,
  "class":"Storage",
  "method":"createStorage",
  "parameter": [true, " metadata=doclen UINT16", "DatabaseClient<4>"],
  "sub": [
    {
    "time":8,
    "object":4,
    "class":"DatabaseClient",
    "method":"createTransaction",
    "parameter": ["DatabaseTransaction<5>"]
    },
    {
    "time":9,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "VTermNo", "&#1;"]
    },
    {
    "time":10,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "VTypeNo", "&#1;"]
    },
    {
    "time":11,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "VDocNo", "&#1;"]
    },
    {
    "time":12,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "VAttribNo", "&#1;"]
    },
    {
    "time":13,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "VNofDocs", "&#0;"]
    },
    {
    "time":14,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "VByteOrderMark", "&#251;&#128;&#160;&#132;&#128;"]
    },
    {
    "time":15,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "VVersion", "\t"]
    },
    {
    "time":16,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"write",
    "parameter": [null, "M", "doclen UInt16"]
    },
    {
    "time":17,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"commit",
    "parameter": [true]
    },
    {
    "time":18,
    "object":5,
    "class":"DatabaseTransaction",
    "method":"Destructor"
    }
  ]
  },
  {
  "time":19,
  "object":4,
  "class":"DatabaseClient",
  "method":"Destructor"
  },
  {
  "time":20,
  "object":1,
  "class":"StorageObjectBuilder",
  "method":"Destructor"
  },
  {
  "time":21,
  "object":2,
  "class":"Database",
  "method":"Destructor"
  },
  {
  "time":22,
  "object":3,
  "class":"Storage",
  "method":"Destructor"
  }
]
}

对于一个仅创建存储的方法来说,输出已经相当大了。您可以想象,当执行更复杂的操作时,输出可能会变得非常巨大。

使用 breakpoint 跟踪日志记录器,我们可以选择输出日志中的一个方法调用,例如时间为 14 的调用,DatabaseTransactionInterface::write 的所有方法,并使用 "log=breakpoint;call=14" 作为跟踪配置来调用 strusCreate。如果我们这样做是在调试器中,我们可以通过将断点设置在 'strus_breakpoint' 来在该方法调用处暂停。

编写自己的调用跟踪日志记录器

我们在此介绍一个作为 strus 模块实现的示例跟踪日志记录器,它可以被 strus 程序或语言绑定动态加载。您所要做的就是实现 跟踪日志记录器接口,并将其构建为 strus 模块。

以下代码可供下载(请参阅本文顶部的下载链接)。它实现了一个跟踪日志记录器,该日志记录器计算每个接口类名方法名对的调用次数。

#include "strus/base/dll_tags.hpp"
#include "strus/traceModule.hpp"
#include "strus/traceLoggerInterface.hpp"
#include "strus/errorBufferInterface.hpp"
#include <string>
#include <vector>
#include <map>
#include <iostream>

class TraceLoggerExample
    :public strus::TraceLoggerInterface
{
public:
    explicit TraceLoggerExample( strus::ErrorBufferInterface* errorhnd_)
        :m_errorhnd(errorhnd_),m_logcnt(0){}
    virtual ~TraceLoggerExample()
    {
        close();
    }

    virtual strus::TraceLogRecordHandle
        logMethodCall(
            const char* className,
            const char* methodName,
            const strus::TraceObjectId&)
    {
        char methodid[ 256];
        snprintf( methodid, sizeof(methodid), "%s::%s", className, methodName);
        try
        {
            ++m_callcount[ methodid];
            return ++m_logcnt;
        }
        catch (const std::bad_alloc&)
        {
            m_errorhnd->report( "out of memory");
            return 0;
        }
    }

    virtual void logMethodTermination(
            const strus::TraceLogRecordHandle& ,
            const std::vector<strus::TraceElement>& )
    {}

    virtual bool close()
    {
        try
        {
            std::map<std::string,int>::const_iterator
                    ci = m_callcount.begin(), ce = m_callcount.end();
            for (; ci != ce; ++ci)
            {
                std::cout << ci->first << " called " << ci->second << " times" << std::endl;
            }
            return true;
        }
        catch (const std::bad_alloc&)
        {
            m_errorhnd->report( "out of memory");
            return false;
        }
    }

private:
    strus::ErrorBufferInterface* m_errorhnd;
    std::map<std::string,int> m_callcount;
    strus::TraceLogRecordHandle m_logcnt;
};

static strus::TraceLoggerInterface* createTraceLogger_example(
              const std::string& ,
              strus::ErrorBufferInterface* errorhnd)
{
    try
    {
        return new TraceLoggerExample( errorhnd);
    }
    catch (const std::bad_alloc&)
    {
        errorhnd->report( "out of memory");
        return 0;
    }
}

static const strus::TraceLoggerConstructor tracelogger[] =
{
    {"traceexample", &createTraceLogger_example},
    {0,0}        
};

extern "C" DLL_PUBLIC strus::TraceModule entryPoint;

strus::TraceModule entryPoint( tracelogger);

如果我们构建此模块并重复我们之前的 strusCreate 方法调用,并选择此跟踪日志记录器:

strusDestroy -s path=storage
strusCreate -T "log=traceexample" \
    -M .  -m modstrus_trace_example \
    -s "path=storage; metadata=doclen UINT16"

我们将得到:

storage successfully created.
Database::Destructor called 1 times
Database::createClient called 1 times
Database::createDatabase called 1 times
Database::getConfigParameters called 1 times
DatabaseClient::Destructor called 1 times
DatabaseClient::createTransaction called 1 times
DatabaseTransaction::Destructor called 1 times
DatabaseTransaction::commit called 1 times
DatabaseTransaction::write called 8 times
Storage::Destructor called 1 times
Storage::createStorage called 1 times
Storage::getConfigParameters called 1 times
StorageObjectBuilder::Destructor called 1 times
StorageObjectBuilder::getDatabase called 1 times
StorageObjectBuilder::getStorage called 1 times

恢复

得益于 Strus 中使用的非常严格的设计模式,可以创建一个并实现接口的代理宇宙。这使得像 Strus 中的跟踪和 RPC 这样的功能可以作为其本身的切面。在本文中,我们展示了如何在 Strus 中使用调用跟踪。我们希望跟踪的可用性能够提高信任度,并吸引更多用户使用 Strus。要了解更多关于 Strus 的信息,请参阅 我关于 Strus 的其他文章

© . All rights reserved.