7

修订摘要

好吧,看起来系统调用肯定与 GC 有关,而根本问题只是 GC 发生得太频繁了。这似乎与 splitWhen 和 pack 的使用有关,我可以通过分析来判断。

splitWhen 的实现将每个块从惰性文本转换为严格文本,并将它们全部连接起来,因为它建立了一个块缓冲区。这势必会分配很多。

pack,因为它正在从一种类型转换为另一种类型,所以必须分配,这在我的内部循环中,所以这也是有道理的。

原始问题

我在基于 haskell 枚举器的 IO 中偶然发现了一些令人惊讶的系统调用活动。希望有人能对此有所了解。

我一直在玩弄我曾经写了几个月的快速 perl 脚本的 haskell 版本,时断时续。该脚本从每一行读取一些 json,然后打印出一个特定字段(如果存在)。

这是 perl 版本,以及我如何运行它。

cat ~/sample_input | perl -lpe '($_) = grep(/type/, split(/,/))' > /dev/null

这是 haskell 版本(它的调用方式与 perl 版本类似)。

{-# LANGUAGE OverloadedStrings #-}
import qualified Data.Enumerator as E
import qualified Data.Enumerator.Internal as EI
import qualified Data.Enumerator.Text as ET
import qualified Data.Enumerator.List as EL
import qualified Data.Text as T
import qualified Data.Text.IO as TI
import Data.Functor
import Control.Monad
import qualified Data.Text.Lazy as TL
import qualified Data.Text.Lazy.IO as TLI
import System.Environment
import System.IO (stdin, stdout)
import GHC.IO.Handle (hSetBuffering, BufferMode(BlockBuffering))

fieldEnumerator field = enumStdin E.$= splitOn [',','\n'] E.$= grabField field

enumStdin = ET.enumHandle stdin

splitOn :: [Char] -> EI.Enumeratee T.Text T.Text IO b
splitOn chars = (ET.splitWhen (`elem` chars))

grabField :: String -> EI.Enumeratee T.Text T.Text IO b
grabField = EL.filter . T.isInfixOf . T.pack

intercalateNewlines = EL.mapM_ (\field -> (TI.putStrLn field >> (putStr "\n\n")))

runE enum = E.run_ $ enum E.$$ intercalateNewlines

main = do
  (field:_) <- getArgs
  runE $ fieldEnumerator field

令人惊讶的是,haskell 版本的跟踪看起来像这样(实际的 JSON 被抑制,因为它是来自工作的数据),而 perl 版本则符合我的预期;一堆读取,然后是写入,重复。

55333/0x8816f5:    366125       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    366136       3      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    367209       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    367218       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    368449       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    368458       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    369525       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    369534       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    370610       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    370620       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    371735       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    371744       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    371798       5      2 select(0x1, 0x7FFF5FBFBA70, 0x7FFF5FBFB9F0, 0x0, 0x7FFF5FBFBAF0)        = 1 0
55333/0x8816f5:    371802       3      1 read(0x0, SOME_JSON, 0x1FA0)      = 8096 0
55333/0x8816f5:    372907       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    372918       3      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    374063       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    374072       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    375147       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    375156       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    376283       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    376292       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    376809       6      2 select(0x1, 0x7FFF5FBFBA70, 0x7FFF5FBFB9F0, 0x0, 0x7FFF5FBFBAF0)        = 1 0
55333/0x8816f5:    376814       5      3 read(0x0, SOME_JSON, 0x1FA0)      = 8096 0
55333/0x8816f5:    377378       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    377387       3      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    378537       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    378546       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    379598       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    379604       3      0 sigreturn(0x7FFF5FBFF9A0, 0x1E, 0x1)        = 0 Err#-2
55333/0x8816f5:    379613       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    380667       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    380678       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    381862       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    381871       3      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    382032       6      2 select(0x1, 0x7FFF5FBFBA70, 0x7FFF5FBFB9F0, 0x0, 0x7FFF5FBFBAF0)        = 1 0
55333/0x8816f5:    382036       4      2 read(0x0, SOME_JSON, 0x1FA0)        = 8096 0
55333/0x8816f5:    383064       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    383073       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    384118       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    384127       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    385206       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    385215       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    386348       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    386358       3      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    387468       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    387477      11      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    387614       6      2 select(0x1, 0x7FFF5FBFBA70, 0x7FFF5FBFB9F0, 0x0, 0x7FFF5FBFBAF0)        = 1 0
55333/0x8816f5:    387620       5      3 read(0x0, SOME_JSON, 0x1FA0)        = 8096 0
55333/0x8816f5:    388597       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    388606       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    389707       3      0 sigprocmask(0x1, 0x10069BFA8, 0x10069BFAC)      = 0x0 0
55333/0x8816f5:    389716       2      0 sigprocmask(0x3, 0x10069BFAC, 0x0)      = 0x0 0
55333/0x8816f5:    390261       7      3 select(0x2, 0x7FFF5FBFBA70, 0x7FFF5FBFB9F0, 0x0, 0x7FFF5FBFBAF0)        = 1 0
55333/0x8816f5:    390273       6      3 write(0x1, SOME_OUTPUT, 0x1FA0)      = 8096 0
4

4 回答 4

7

从评论中将此提升到最高级别:

FWIW,我正在经历运行时(我们也在 IRC 中讨论这个),并且 sigprocmask 只有两种用途:GC 和 tty 驱动程序。后者不太可能,我建议进行分析以验证它正在执行大量 GC 并尝试找出原因。

事实证明(来自 IRC)它为 0.5MB 的数据分配了 90MB,并且垃圾收集器确实被触发了很多。所以现在要归结为为什么枚举器要进行如此多的额外分配。

于 2012-04-23T03:45:01.610 回答
7

您是否担心分配或(开销来自?)对 sigprocmask 的调用?

如果是前者并且你想使用这个enumerator包,这个小改动可以帮助 4k 测试集减少大约 50%:8MB 的分配减少到 4MB,gen0 GC 从 15 到 6。

splitOn :: EI.Enumeratee T.Text T.Text IO b
splitOn = EL.concatMap (T.split fastSplit)

fastSplit :: Char -> Bool
fastSplit ','  = True
fastSplit '\n' = True
fastSplit _    = False

之前(来自 的统计数据+RTS -sstderr -RTS):

       在堆中分配了 8,212,680 字节
         GC 期间复制了 696,184 个字节
         148,656 字节最大驻留(1 个样本)
          30,664 字节最大斜率
               2 MB 总内存在使用(0 MB 由于碎片丢失)

                                    总时间(经过) 平均暂停 最大暂停
  Gen 0 15 colls,0 par 0.00s 0.00s 0.0001s 0.0005s
  Gen 1 1 colls, 0 par 0.00s 0.00s 0.0010s 0.0010s

后:

       在堆中分配了 3,838,048 字节
         GC 期间复制了 689,592 个字节
         148,368 字节最大驻留(1 个样本)
          27,040 字节最大斜率
               2 MB 总内存在使用(0 MB 由于碎片丢失)

                                    总时间(经过) 平均暂停 最大暂停
  Gen 0 6 colls,0 par 0.00s 0.00s 0.0001s 0.0003s
  Gen 1 1 colls, 0 par 0.00s 0.00s 0.0006s 0.0006s

这是一个相当合理的改进,但肯定还有一些不足之处。我没有过多地踢枚举器,而是尝试在导管 0.4.1 中重写它,只是为了踢球。应该是等价的...

import Data.Conduit as C
import qualified Data.Conduit.Binary as Cb
import qualified Data.Conduit.List as Cl
import qualified Data.Conduit.Text as Ct
import qualified Data.Text as T
import qualified Data.Text.IO as TI
import Control.Monad.Trans (MonadIO, liftIO)
import System.Environment
import System.IO (stdin)

grabField :: Monad m => String -> Conduit T.Text m T.Text
grabField = Cl.filter . T.isInfixOf . T.pack

printField :: MonadIO m => T.Text -> m ()
printField field = liftIO $ do
  TI.putStrLn field
  putStr "\n\n"

fastSplit :: Char -> Bool
fastSplit ','  = True
fastSplit '\n' = True
fastSplit _    = False

main :: IO ()
main = do
  field:_ <- getArgs
  runResourceT $ Cb.sourceHandle stdin
              $$ Ct.decode Ct.utf8
              =$ Cl.concatMap (T.split fastSplit)
              =$ grabField field
              =$ Cl.mapM_ printField

...但由于某种原因分配并保留更少的内存:

         在堆中分配了 835,688 字节
           GC 期间复制了 8,576 个字节
          87,200 字节最大驻留(1 个样本)
          19,968 字节最大斜率
               1 MB 总内存在使用(0 MB 由于碎片丢失)

                                    总时间(经过) 平均暂停 最大暂停
  Gen 0 1 colls, 0 par 0.00s 0.00s 0.0000s 0.0000s
  Gen 1 1 colls, 0 par 0.00s 0.00s 0.0008s 0.0008s
于 2012-04-23T06:17:33.087 回答
4

如果在这些 sigsetmasks 之间读取的数据量很大,我的第一个猜测是运行时在 gc 运行之前执行 sigsetmask,因此 gc 不会因堆处于不一致状态而中断。

于 2012-04-23T03:01:00.030 回答
3

多于评论而不是答案:如果您通过 GHC 源 grep,您将看到posix/TTY.c(TERMIOS 代码) 和sm/GC.c(via {,un}blockUserSignals) 有最有可能的候选人。您可以使用调试符号编译 GHC,或者只添加一些虚拟(唯一)系统调用,以确保您可以区分两个系统调用配置文件以找出答案。另一个便宜的测试是删除任何终端交互,如果掩蔽行为消失,那么这将是支持 GC 的温和证据(没有答案)。

编辑:我应该承认一些库代码也可以调用sigprocmask,我忽略了它作为不太可能的来源,但它实际上可能是问题!

于 2012-04-23T03:35:44.090 回答