相同逻辑的响应时间在不同的并发请求下快速增长

Question

我正在使用 tomcat 来服务我的应用程序，并且我使用 ab 来测试响应时间。

这是servlet中的核心逻辑：

    long st = System.currentTimeMillis();
    data = server.getData(req);  //
    System.out.println("get data cost:" + (System.currentTimeMillis() - st));

    st = System.currentTimeMillis();
    if (data != null) {
        try {
            OutputStream out = resp.getOutputStream();
            data.save(out);
            out.flush();
            System.out.println("save data cost:" + (System.currentTimeMillis() - st));
        } catch (IOException e) {
            status = 500;
        }
    }

@Override
public IData getData(HttpServletRequest req) {
    String layers = req.getParameter("layers");
    String id = req.getParameter("id");
    ArrayList<BufferedImage> result = new ArrayList<BufferedImage>();
    for (String layer : layers) {
        String lkey = layer+"-"+id;
        BufferedImage cachedImage = null;
        if (cacher.contains(lkey)) {
            cachedImage = (BufferedImage) cacher.get(lkey);
        } else {
            cachedImage =...  // heavy operation which will cost 1s for a single request
        }

        if (cachedImage != null) {
            result.add(cachedImage);
        }

    }
    return new Data(result);
}

class Data implements IData {
    private BufferedImage imageResult;

    public Data(ArrayList<BufferedImage> data) {
        imageResult = new BufferedImage(500 ,500 , BufferedImage.TYPE_INT_ARGB);
        Graphics2D g = imageResult.createGraphics();
        for (BufferedImage img : data) {
            g.drawImage(img, 0, 0, null);
        }
        g.dispose();
    }

    @Override
    public void save(OutputStream out, String format) throws IOException {
        PngEncoder encoder = new PngEncoder(PngEncoder.COLOR_TRUECOLOR_ALPHA);
        encoder.encode(imageResult, out);
        imageResult = null;
    }
}

如图所示，

测试用例（我对请求的数据使用缓存，我在测试前运行了一次url，所以我确信在下面的测试用例中所有的数据都是从缓存中检索到的）：

与 ab：ab -n 1 -c 1 ...

响应时间：80ms

并记录：

get data cost:11
save data cost:68

使用：ab -n 10 -c 10 ...

  50%    206
  66%    212
  75%    225
  80%    228
  90%    244
  95%    244
  98%    244
  99%    244
 100%    244 (longest request)

还有日志：

http://paste.ubuntu.com/7758426/

使用：ab -n 100 -c 100 ..

  50%   2412
  66%   2414
  75%   2415
  80%   2415
  90%   2418
  95%   2418
  98%   2426
  99%   2433
 100%   2433 (longest request)

还有日志：

http://paste.ubuntu.com/7758421/

IMO，保存数据所需的时间应取决于所做的工作。在示例中，保存操作仅需 70 ms。为什么它在处理 100 个并发用户时增长如此之快？

这正常吗？

如果是，有什么办法可以减少响应时间？

如果不是，我可能遗漏了一些东西，我该如何解决？

---

更新（整个逻辑）：

我正在提供像谷歌地图这样的地图图块，一个图块由一个坐标（x、y 和缩放）定位。同时，地图可能包含多个图层，例如道路、水、土地利用等。我们在应用程序中提供 50 多个图层。

例如，用户可以通过一个简单的请求从我们的服务器获取磁贴：

http://localhost/tile/z/x/y.png?layer=road,water 

这将返回一个仅包含road 和water 层的图块（图像）。

或

http://localhost/tile/z/x/y.png?layer=road,water,landuse,poi 

这将返回一个包含road、water、landuse 和poi 层的图块（图像）。

如图所示，我们总共有 50+ 层，所以有很多“排列组合”，所以我们必须动态生成图块。

但是创建图块是一项耗时的工作，所以我们在这里使用缓存。以请求http://localhost/tile/z/x/y.png?layer=road,water为例，我们将检查给定图层的给定（x，y，zoom）处的tile（BufferedImage）是否存在，如果不存在，则创建它并将其放入缓存中。

ArrayList<BufferedImage> combined=new ArrayList<BufferedImage>();
for(String layer : requset.getParameter("layer")){
    String cacheKey = x+"-"+y+"-"+"+zoom+"-"+layer;
    BufferedImage image = cache.get(cacheKey);
    if(image ==nul){
        //generate it dynamically

        //put it to cache
        cache.add(cacheKey,image)
    }   
    combined.add(image)
}

然后我们将合并后的图像写入客户端（Data.save 做了什么）。

这是整个逻辑，如果不清楚，请告诉我。

Answer 1

答案取决于您的线程工作是阻塞还是非阻塞，以及您可以在您的机器上实现的并行度。

但是，您在问题中报告的时间似乎表明您的请求只是一个接一个地排队，而不是完全并行处理。

这可能是因为您有 10 个内核，因此您只能真正同时处理 10 个请求。在这种情况下，您无能为力，除非您分布在更多机器上或获得更强大的 CPU。

这也可能发生，因为您的data.save() 是一个需要锁定共享资源的操作，因此锁定导致您的工作被序列化。如果是这种情况，您可以尝试通过设置仅偶尔同步的每个线程状态（例如每 10000 个请求）来减少同步。

在任何一种情况下，您的响应时间（延迟）都完全取决于您的吞吐量，而不是处理一个请求所需的时间，正如您在无负载情况下所期望的那样。

Answer 2

将 VisualVM 附加到 Tomcat。您将能够查看问题是使用 CPU 还是线程不足。现在，看到 PNG 代码，我的猜测是图形操作需要时间，但这只是一个猜测。剖析会给你一个真正的答案。