3

我正在使用以下代码进行日志记录，作为处理我的请求的一部分。这段代码在任何地方都出现过很多次。当我进行多个并行调用时，由于这段代码，我遇到了死锁。

(defn log [msg & vals]
  (let [line (apply format msg vals)]
    (locking System/out (println line))))

任何人都知道这里可能出了什么问题。

谢谢

4

2 回答 2

5

概括

我推测死锁是由于log' 与其他代码的交互；特别是，在 REPL 进行测试时，这是可以预料的，原因我将在下面说明。（意思是直接 Clojure REPL，而不是lein repl其他基于 nrepl 的 repl 等）

涉及的关键问题与同步 on 有关System/out，这说明了在 JDK 或 Clojure 本身提供的对象上同步并不是一个好主意，因为这很可能会干扰涉及这些对象的现有锁定协议（实际上 Clojure 的*out*and就是这种情况System/out，我们很快就会看到）。这说明的另一点是锁不组合。

答案从提供一个解决方案开始，然后才进入 Clojure 打印中涉及的锁定协议的细节，因为后面的讨论有点冗长，基本建议可以非常简洁地陈述。

建议的解决方案

看待这种情况的一种方法是，如上所述，在核心 JVM 类或 Clojure 提供的对象上进行同步并不是一个好主意，因为这很可能会干扰这些对象的锁定协议已经是一部分。相反，人们总是可以引入新的哨兵对象，然后拥有这些对象并对其进行同步：

(def ^:private log-sentinel (Object.))

(defn log [msg & vals]
  (let [line (apply format msg vals)]
    (locking log-sentinel
      (println line)))

您仍然可能会以输出交错的形式受到不相关打印输出的干扰，但大多数时候您根本不应该有任何此类打印输出（除了 REPL 提示打印输出，其无序应该不是太大的问题; 调试打印输出也可以使用log，无论如何，这些将在生产中关闭，对吗？），否则您可能更喜欢将日志输出打印到不同的输出流。

此外，由于稍后将讨论的原因，在这种情况下甚至不需要使用自己的锁，只要一个使用print代替println; print调用在这里只接受一个参数这一事实是关键：

(defn log [msg & vals]
  (let [line (str (apply format msg vals) "\n")]
    (print line)))

flush如果您想立即打印输出，您可以在最后添加一个调用。（然后有可能flush在另一个线程之后发生print，但无论如何打印输出都会立即发生。）

这个版本log是我推荐的版本。这可能是最简单的解决方案；此外，它还可以保护您的打印输出不会与通过 Clojure 打印功能的任何其他打印输出交错。

打印设备的锁定协议

注意事项：据我所知，我在下面描述的行为在 JDK 文档中的任何地方都没有提及，因此对它的任何依赖都需要您自担风险（尽管这可能不是一个可怕的风险。）

在这种特殊情况下，值得注意的是*out*已经有一个锁定协议，它保证来自print& Friends 的各个输出位（例如他们各个参数的表示，它们之间添加的空格和prn/添加的换行符println）将不被交错。

它的工作方式是*out*默认存储一个java.io.OutputStreamWriter包装java.lang.System.out，也称为System/out. 这个java.io.OutputStreamWriter实例（实际上是任何java.io.Writer实例）在一个受保护的lock字段中存储了一个在执行写入时同步的对象。在 的情况下*out*，该对象恰好是System/out。print和朋友只需将他们的参数（和中间空格）*out*一一提供，因此，如上所述，任何单个参数都受到保护，不会与输出中的其他数据交错，但单个print调用的多个参数可能会被分解。因此，构建一个字符串然后打印它是线程安全的，而多参数print在更简单的场景中很方便。

System/out在 REPL锁定时出现死锁的原因

在这一点上，我想重申一下，我认为避免使用内置对象在（1）上同步的锁定协议无论如何都是一个好主意，（2）现在应该有望解决您的问题，（3）是我可以推荐而无需询问有关您的代码库的更多详细信息。继续描述为什么 REPL 会出现这种行为。下面的讨论适用于直接 Clojure REPL，而不是lein repl等。

首先，synchronized（Java）/ （Clojure）获得的锁是可重入的，这就解释了你的函数在单线程使用locking中没有问题——很明显，一旦控制到达了表单的主体，当前的线程将能够成功打印（因为它已经拥有监视器）。loglockinglineSystem/out

引入死锁涉及System/out很简单：

(locking System/out
  @(future (println :foo))) ; note the @ !

中间有函数调用，系统可能会死锁，也可能不会死锁：

(defn f [fut]
  (locking System/out
    @fut))

;; will deadlock or not depending on whether the future is quick enough
(f (future (println :foo)))

扩展上面代码片段中的注释，如果 future 在获取锁定之前无法完成所有打印（这里涉及:foo、换行符和可能的刷新操作，尽管最后一部分取决于 的当前值*flush-on-newline*）， it 和的线程会死锁。如果 future 打印速度非常快，它会在获取锁之前完成，一切都会好起来的。fSystem/outff

现在，在 REPL 中工作时，可能会出现类似的情况：

(defn f [i]
  (locking System/out
    (println :foo i)))

(dotimes [i 10]
  (future (f i)))

这在我的机器上一直死锁而没有打印任何东西。随着迭代次数达到 10000 次，它反而倾向于在死锁之前获得相当多的打印输出，每个打印输出都在自己的行上。

相比之下，

(defn f [i]
  (println :foo i))

(dotimes [i 10]
  (future (f i)))

打印出它应该打印的所有内容，但“没有特定的顺序”；特别是，下一个提示出现在某个任意位置，通常不在打印文本的末尾附近。

请注意，在每种情况下，如果打印任何内容，每个单独的项目（:foo、整数、空格、换行符）都会单独打印（即没有交错）。这当然是由于前面提到的由 执行的锁定*out*。

于 2013-08-10T10:31:16.953 回答
-1

从锁定文档：

在隐式 do 中执行 expr，同时持有 x 的监视器。在任何情况下都会释放 x 的监视器。

你拿着 System.out 的监视器，当你有多个并行调用时，你会得到一个死锁异常。

尽管“在所有情况下都会释放 x 的监视器”对我来说并不是很清楚。

为了进行实验，请尝试删除对（锁定）函数的调用，并查看您的系统是否继续工作。

于 2013-08-10T08:36:01.660 回答