hadoop-common-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Keith Wiley <kwi...@keithwiley.com>
Subject Linear slowdown producing streaming output
Date Sat, 05 Feb 2011 04:07:46 GMT
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 4-5X 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
________________________________________________________________________________


Mime
View raw message