Uploaded image for project: 'MongoDB Database Tools'
  1. MongoDB Database Tools
  2. TOOLS-1855

mongodump fails with "error reading collection: Closed explicitly"

    • Type: Icon: Bug Bug
    • Resolution: Gone away
    • Priority: Icon: Critical - P2 Critical - P2
    • None
    • Affects Version/s: 3.4.10
    • Component/s: mongodump, mongorestore
    • Labels:
    • Environment:
    • v3.4

      Doing a piped mongodump -> mongorestore to copy a specific collection between two clusters via this command:

      mongodump -host $SOURCE --port 27017 --db $DB --collection $COLLECTION --archive | mongorestore --drop -vvvvvv --host $TARGET --port 27017-db $DB --archive

      This is performed ON the target system, to prevent cpu usage on the active source. Both systems are on the same physical local network with 10gbe connectivity. There are no timeouts configured for ssh OR for mongo.

      Here is the command output:

      2017-11-01T20:10:04.343-0400    checking options
      2017-11-01T20:10:04.344-0400            dumping with object check disabled
      2017-11-01T20:10:04.344-0400    will listen for SIGTERM, SIGINT, and SIGKILL
      2017-11-01T20:10:04.356-0400    connected to node type: standalone
      2017-11-01T20:10:04.356-0400    standalone server: setting write concern w to 1
      2017-11-01T20:10:04.356-0400    using write concern: w='1', j=false, fsync=false, wtimeout=0
      2017-11-01T20:10:04.356-0400    the --db and --collection args should only be used when restoring from a BSON file. Other uses are deprecated and will not exist in the future; use --nsInclude instead
      2017-11-01T20:10:04.367-0400    writing [db.Collection] to archive on stdout
      2017-11-01T20:10:04.382-0400    archive prelude [db.Collection]
      2017-11-01T20:10:04.382-0400    archive format version "0.1"
      2017-11-01T20:10:04.382-0400    archive server version "3.4.0"
      2017-11-01T20:10:04.382-0400    archive tool version "r3.4.10"
      2017-11-01T20:10:04.387-0400    preparing collections to restore from
      2017-11-01T20:10:04.387-0400    using  as dump root directory
      2017-11-01T20:10:04.387-0400    reading collections for database db in Collection
      2017-11-01T20:10:04.387-0400    skipping restoring [db.Collection], it is not included
      2017-11-01T20:10:04.387-0400    demux Open
      2017-11-01T20:10:04.387-0400    skipping restoring [db.Collection] metadata, it is not included
      2017-11-01T20:10:04.652-0400    demux namespaceHeader: {db Collection false 0}
      2017-11-01T20:10:07.342-0400    [........................]  db.Collection  996264/2292892069  (0.0%)
      ...
      2017-11-01T20:21:00.859-0400    [#.......................]  db.Collection  134266416/2292892069  (5.9%)
      2017-11-01T20:21:00.863-0400    Failed: error writing data for collection `db.Collection` to disk: error reading collection: Closed explicitly
      2017-11-01T20:21:00.863-0400    demux namespaceHeader: {db Collection true -1341316949384315787}
      2017-11-01T20:21:00.863-0400    demux checksum for namespace eventTrack.WebCompanionStats was not calculated.
      2017-11-01T20:21:00.864-0400    demux End
      2017-11-01T20:21:00.864-0400    demux finishing (err:<nil>)
      2017-11-01T20:21:00.864-0400    restoring up to 4 collections in parallel
      2017-11-01T20:21:00.864-0400    starting restore routine with id=3
      2017-11-01T20:21:00.864-0400    ending restore routine with id=3, no more work to do
      2017-11-01T20:21:00.864-0400    starting restore routine with id=0
      2017-11-01T20:21:00.864-0400    ending restore routine with id=0, no more work to do
      2017-11-01T20:21:00.864-0400    starting restore routine with id=2
      2017-11-01T20:21:00.864-0400    ending restore routine with id=2, no more work to do
      2017-11-01T20:21:00.864-0400    starting restore routine with id=1
      2017-11-01T20:21:00.864-0400    ending restore routine with id=1, no more work to do
      2017-11-01T20:21:00.864-0400    done
      
      

      The time period seems very odd (11 minutes) and so I'm curious about what could cause the source (read) to explicitly close the connection. There are no logs on the source server's mongod from this time indicating a connection was terminated.

            Assignee:
            mark.agarunov Mark Agarunov
            Reporter:
            alexander.bale@lavasoft.com Alexander Martin-Bale
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: