I noticed that it takes much longer to write 55 MBs to a streaming output than it takes to
write 12 MBs (much more than 45X longer), so I broke the output up, writing 1 MB at a time
and discovered a perfectly linear slowdown. Bottom line, the more data I have already written
to stdout from a streaming task, the longer it takes to write the next block of data. I have
no idea if this is intrinsic to producing stdout from any Unix process (I've never heard of
such a thing) or if this is a Hadoop issue. Does anyone have any idea what's going on here?
From pos 0, wrote 1048576 bytes. Next pos will be 1048576.
diffTimeWriteOneBlock: 0.31s
From pos 1048576, wrote 1048576 bytes. Next pos will be 2097152.
diffTimeWriteOneBlock: 0.9s
From pos 2097152, wrote 1048576 bytes. Next pos will be 3145728.
diffTimeWriteOneBlock: 1.46s
From pos 3145728, wrote 1048576 bytes. Next pos will be 4194304.
diffTimeWriteOneBlock: 1.98s
From pos 4194304, wrote 1048576 bytes. Next pos will be 5242880.
diffTimeWriteOneBlock: 2.47s
From pos 5242880, wrote 1048576 bytes. Next pos will be 6291456.
diffTimeWriteOneBlock: 3.06s
From pos 6291456, wrote 1048576 bytes. Next pos will be 7340032.
diffTimeWriteOneBlock: 3.53s
From pos 7340032, wrote 1048576 bytes. Next pos will be 8388608.
diffTimeWriteOneBlock: 3.96s
From pos 8388608, wrote 1048576 bytes. Next pos will be 9437184.
diffTimeWriteOneBlock: 4.24s
From pos 9437184, wrote 1048576 bytes. Next pos will be 10485760.
diffTimeWriteOneBlock: 4.74s
From pos 10485760, wrote 1048576 bytes. Next pos will be 11534336.
diffTimeWriteOneBlock: 5.24s
From pos 11534336, wrote 1048576 bytes. Next pos will be 12582912.
diffTimeWriteOneBlock: 5.72s
From pos 12582912, wrote 1048576 bytes. Next pos will be 13631488.
diffTimeWriteOneBlock: 6.25s
From pos 13631488, wrote 1048576 bytes. Next pos will be 14680064.
diffTimeWriteOneBlock: 6.77s
From pos 14680064, wrote 1048576 bytes. Next pos will be 15728640.
diffTimeWriteOneBlock: 7.37s
From pos 15728640, wrote 1048576 bytes. Next pos will be 16777216.
diffTimeWriteOneBlock: 7.76s
From pos 16777216, wrote 1048576 bytes. Next pos will be 17825792.
diffTimeWriteOneBlock: 8.74s
From pos 17825792, wrote 1048576 bytes. Next pos will be 18874368.
diffTimeWriteOneBlock: 8.99s
From pos 18874368, wrote 1048576 bytes. Next pos will be 19922944.
diffTimeWriteOneBlock: 9.35s
From pos 19922944, wrote 1048576 bytes. Next pos will be 20971520.
diffTimeWriteOneBlock: 9.85s
From pos 20971520, wrote 1048576 bytes. Next pos will be 22020096.
diffTimeWriteOneBlock: 10.43s
From pos 22020096, wrote 1048576 bytes. Next pos will be 23068672.
diffTimeWriteOneBlock: 11.05s
From pos 23068672, wrote 1048576 bytes. Next pos will be 24117248.
diffTimeWriteOneBlock: 11.52s
From pos 24117248, wrote 1048576 bytes. Next pos will be 25165824.
diffTimeWriteOneBlock: 12.23s
From pos 25165824, wrote 1048576 bytes. Next pos will be 26214400.
diffTimeWriteOneBlock: 12.49s
From pos 26214400, wrote 1048576 bytes. Next pos will be 27262976.
diffTimeWriteOneBlock: 13.1s
From pos 27262976, wrote 1048576 bytes. Next pos will be 28311552.
diffTimeWriteOneBlock: 13.83s
From pos 28311552, wrote 1048576 bytes. Next pos will be 29360128.
diffTimeWriteOneBlock: 14.31s
From pos 29360128, wrote 1048576 bytes. Next pos will be 30408704.
diffTimeWriteOneBlock: 14.65s
From pos 30408704, wrote 1048576 bytes. Next pos will be 31457280.
diffTimeWriteOneBlock: 15.32s
From pos 31457280, wrote 1048576 bytes. Next pos will be 32505856.
diffTimeWriteOneBlock: 15.88s
From pos 32505856, wrote 1048576 bytes. Next pos will be 33554432.
diffTimeWriteOneBlock: 16.77s
From pos 33554432, wrote 1048576 bytes. Next pos will be 34603008.
diffTimeWriteOneBlock: 16.9s
From pos 34603008, wrote 1048576 bytes. Next pos will be 35651584.
diffTimeWriteOneBlock: 17.39s
From pos 35651584, wrote 1048576 bytes. Next pos will be 36700160.
diffTimeWriteOneBlock: 18.12s
From pos 36700160, wrote 1048576 bytes. Next pos will be 37748736.
diffTimeWriteOneBlock: 18.69s
From pos 37748736, wrote 1048576 bytes. Next pos will be 38797312.
diffTimeWriteOneBlock: 19.09s
From pos 38797312, wrote 1048576 bytes. Next pos will be 39845888.
diffTimeWriteOneBlock: 19.7s
From pos 39845888, wrote 1048576 bytes. Next pos will be 40894464.
diffTimeWriteOneBlock: 20.65s
From pos 40894464, wrote 1048576 bytes. Next pos will be 41943040.
diffTimeWriteOneBlock: 20.71s
From pos 41943040, wrote 1048576 bytes. Next pos will be 42991616.
diffTimeWriteOneBlock: 21.49s
From pos 42991616, wrote 1048576 bytes. Next pos will be 44040192.
diffTimeWriteOneBlock: 22.1s
From pos 44040192, wrote 1048576 bytes. Next pos will be 45088768.
diffTimeWriteOneBlock: 22.48s
From pos 45088768, wrote 1048576 bytes. Next pos will be 46137344.
diffTimeWriteOneBlock: 23.36s
From pos 46137344, wrote 1048576 bytes. Next pos will be 47185920.
diffTimeWriteOneBlock: 23.84s
From pos 47185920, wrote 1048576 bytes. Next pos will be 48234496.
diffTimeWriteOneBlock: 24.23s
From pos 48234496, wrote 1048576 bytes. Next pos will be 49283072.
diffTimeWriteOneBlock: 25.07s
From pos 49283072, wrote 1048576 bytes. Next pos will be 50331648.
diffTimeWriteOneBlock: 25.56s
From pos 50331648, wrote 1048576 bytes. Next pos will be 51380224.
diffTimeWriteOneBlock: 26.27s
From pos 51380224, wrote 1048576 bytes. Next pos will be 52428800.
diffTimeWriteOneBlock: 26.79s
From pos 52428800, wrote 1048576 bytes. Next pos will be 53477376.
diffTimeWriteOneBlock: 27.47s
From pos 53477376, wrote 1048576 bytes. Next pos will be 54525952.
diffTimeWriteOneBlock: 27.98s
From pos 54525952, wrote 1048576 bytes. Next pos will be 55574528.
diffTimeWriteOneBlock: 28.53s
From pos 55574528, wrote 205312 bytes. Next pos will be 55779840.
diffTimeWriteOneBlock: 7.22s
________________________________________________________________________________
Keith Wiley kwiley@keithwiley.com keithwiley.com music.keithwiley.com
"I do not feel obliged to believe that the same God who has endowed us with
sense, reason, and intellect has intended us to forgo their use."
 Galileo Galilei
________________________________________________________________________________
