Uploaded image for project: 'Hadoop Map/Reduce'
  1. Hadoop Map/Reduce
  2. MAPREDUCE-7319

Log list of mappers at trace level in ShuffleHandler audit log

    XMLWordPrintableJSON

    Details

    • Type: Improvement
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 3.4.0
    • Fix Version/s: 3.4.0, 3.3.1, 2.10.2, 3.2.3
    • Component/s: yarn
    • Labels:
      None

      Description

      MAPREDUCE-6958 added the content length to ShuffleHandler audit log, which is logged at DEBUG level. After enabling it, we found that the list of mappers for large jobs was filling up our audit logs. It would be good to move the list of mappers to TRACE level to reduce the logging impact without disabling the log message entirely.

      For example a log message like this:

      2018-01-25 23:43:02,669 [New I/O worker #1] DEBUG ShuffleHandler.audit: shuffle for job_1512479762132_1318600 reducer 241 length 482072 mappers: [attempt_1512479762132_1318600_1_00_004852_0_10003,
      attempt_1512479762132_1318600_1_00_004190_0_10003, attempt_1512479762132_1318600_1_00_004393_0_10003, attempt_1512479762132_1318600_1_00_005057_0_10003, attempt_1512479762132_1318600_1_00_004855_0_10002,
      attempt_1512479762132_1318600_1_00_003976_0_10003, attempt_1512479762132_1318600_1_00_004058_0_10003, attempt_1512479762132_1318600_1_00_004355_0_10003, attempt_1512479762132_1318600_1_00_004436_0_10002,
      attempt_1512479762132_1318600_1_00_004854_0_10003, attempt_1512479762132_1318600_1_00_005174_0_10004, attempt_1512479762132_1318600_1_00_003972_0_10002, attempt_1512479762132_1318600_1_00_004853_0_10002,
      attempt_1512479762132_1318600_1_00_004856_0_10002]
      

      Would become this with log4j.logger.org.apache.hadoop.mapred.ShuffleHandler.audit=DEBUG:

      2018-01-25 23:43:02,669 [New I/O worker #1] DEBUG ShuffleHandler.audit: shuffle for job_1512479762132_1318600 reducer 241 length 482072
      

      And this with log4j.logger.org.apache.hadoop.mapred.ShuffleHandler.audit=TRACE:

      2018-01-25 23:43:02,669 [New I/O worker #1] DEBUG ShuffleHandler.audit: shuffle for job_1512479762132_1318600 reducer 241 length 482072
      2018-01-25 23:43:02,669 [New I/O worker #1] TRACE ShuffleHandler.audit: shuffle for job_1512479762132_1318600 mappers: [attempt_1512479762132_1318600_1_00_004852_0_10003,
      attempt_1512479762132_1318600_1_00_004190_0_10003, attempt_1512479762132_1318600_1_00_004393_0_10003, attempt_1512479762132_1318600_1_00_005057_0_10003, attempt_1512479762132_1318600_1_00_004855_0_10002,
      attempt_1512479762132_1318600_1_00_003976_0_10003, attempt_1512479762132_1318600_1_00_004058_0_10003, attempt_1512479762132_1318600_1_00_004355_0_10003, attempt_1512479762132_1318600_1_00_004436_0_10002,
      attempt_1512479762132_1318600_1_00_004854_0_10003, attempt_1512479762132_1318600_1_00_005174_0_10004, attempt_1512479762132_1318600_1_00_003972_0_10002, attempt_1512479762132_1318600_1_00_004853_0_10002,
      attempt_1512479762132_1318600_1_00_004856_0_10002]
      

      One question is whether there are any downstream consumers of this audit log that might have a problem with this change?

        Attachments

        1. MAPREDUCE-7319.001.patch
          1 kB
          Jim Brennan

          Activity

            People

            • Assignee:
              jbrennan Jim Brennan
              Reporter:
              jbrennan Jim Brennan
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: