Home | About | Sematext search-lucene.com search-hadoop.com
 Search Hadoop and all its subprojects:

Switch to Threaded View
Hadoop >> mail # user >> Linear slowdown producing streaming output


Copy link to this message
-
Linear slowdown producing streaming output
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.
    diffTimeWriteOne