Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-53356

Server log is written at pre-truncated position post truncation

    • Type: Icon: Bug Bug
    • Resolution: Works as Designed
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 4.2.10, 4.4.2
    • Component/s: None
    • Labels:
      None
    • Linux
    • Hide

      Start RS node
      Issue `: > path-to-mongod.log`
      Wait 5 seconds

      Show
      Start RS node Issue `: > path-to-mongod.log` Wait 5 seconds

      When I truncate the log using

      : > path-to.log
      

      pattern, the server appears to keep writing the log at the same position where the file was pre-truncation.

      Example shell session:

      serene% ls -l `find /mnt/zram/mongodb/4.4-scm -name \*.log`
      -rw-rw-rw- 1 m m 462548363 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/configRepl/rs1/mongod.log
      -rw-rw-rw- 1 m m  38755955 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14440.log
      -rw-rw-rw- 1 m m  38488489 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14441.log
      -rw-rw-rw- 1 m m  57344569 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard01/rs1/mongod.log
      -rw-rw-rw- 1 m m   3191208 Dec 14 15:46 /mnt/zram/mongodb/4.4-scm/shard01/rs2/mongod.log
      -rw-rw-rw- 1 m m  56094408 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard02/rs1/mongod.log
      -rw-rw-rw- 1 m m   3561329 Dec 14 15:51 /mnt/zram/mongodb/4.4-scm/shard02/rs2/mongod.log
      serene% :>/mnt/zram/mongodb/4.4-scm/shard01/rs1/mongod.log 
      serene% ls -l `find /mnt/zram/mongodb/4.4-scm -name \*.log`
      -rw-rw-rw- 1 m m 462549651 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/configRepl/rs1/mongod.log
      -rw-rw-rw- 1 m m  38756124 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14440.log
      -rw-rw-rw- 1 m m  38488658 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14441.log
      -rw-rw-rw- 1 m m         0 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard01/rs1/mongod.log
      -rw-rw-rw- 1 m m   3191208 Dec 14 15:46 /mnt/zram/mongodb/4.4-scm/shard01/rs2/mongod.log
      -rw-rw-rw- 1 m m  56094408 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard02/rs1/mongod.log
      -rw-rw-rw- 1 m m   3561329 Dec 14 15:51 /mnt/zram/mongodb/4.4-scm/shard02/rs2/mongod.log
      serene% ls -l `find /mnt/zram/mongodb/4.4-scm -name \*.log`
      -rw-rw-rw- 1 m m 462549892 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/configRepl/rs1/mongod.log
      -rw-rw-rw- 1 m m  38756124 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14440.log
      -rw-rw-rw- 1 m m  38488658 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14441.log
      -rw-rw-rw- 1 m m         0 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard01/rs1/mongod.log
      -rw-rw-rw- 1 m m   3191208 Dec 14 15:46 /mnt/zram/mongodb/4.4-scm/shard01/rs2/mongod.log
      -rw-rw-rw- 1 m m  56094408 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard02/rs1/mongod.log
      -rw-rw-rw- 1 m m   3561329 Dec 14 15:51 /mnt/zram/mongodb/4.4-scm/shard02/rs2/mongod.log
      serene% ls -l `find /mnt/zram/mongodb/4.4-scm -name \*.log`
      -rw-rw-rw- 1 m m 462550133 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/configRepl/rs1/mongod.log
      -rw-rw-rw- 1 m m  38756124 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14440.log
      -rw-rw-rw- 1 m m  38488658 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14441.log
      -rw-rw-rw- 1 m m         0 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard01/rs1/mongod.log
      -rw-rw-rw- 1 m m   3191208 Dec 14 15:46 /mnt/zram/mongodb/4.4-scm/shard01/rs2/mongod.log
      -rw-rw-rw- 1 m m  56094408 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard02/rs1/mongod.log
      -rw-rw-rw- 1 m m   3561329 Dec 14 15:51 /mnt/zram/mongodb/4.4-scm/shard02/rs2/mongod.log
      serene% ls -l `find /mnt/zram/mongodb/4.4-scm -name \*.log`
      -rw-rw-rw- 1 m m 462550374 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/configRepl/rs1/mongod.log
      -rw-rw-rw- 1 m m  38756124 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14440.log
      -rw-rw-rw- 1 m m  38488658 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/mongos/mongos_14441.log
      -rw-rw-rw- 1 m m  57344811 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard01/rs1/mongod.log
      -rw-rw-rw- 1 m m   3191208 Dec 14 15:46 /mnt/zram/mongodb/4.4-scm/shard01/rs2/mongod.log
      -rw-rw-rw- 1 m m  56094650 Dec 14 15:53 /mnt/zram/mongodb/4.4-scm/shard02/rs1/mongod.log
      -rw-rw-rw- 1 m m   3561329 Dec 14 15:51 /mnt/zram/mongodb/4.4-scm/shard02/rs2/mongod.log
      

      You can see how the size of shard01 rs1 log jumped from 0 to 50 megs.

      Since the file was earlier truncated, it now has (in the above example) 50 megs of null bytes followed by the log data.

      I expected the server to write the log at the current position so that after truncation I just have the post-truncation data starting from the beginning of the file.

      I tested 4.2.10 also with same results and the truncate(1) command with also same results.

            Assignee:
            Unassigned Unassigned
            Reporter:
            oleg.pudeyev@mongodb.com Oleg Pudeyev (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: