Skip to content

Instantly share code, notes, and snippets.

@vmorris
Created October 10, 2016 16:15
Show Gist options
  • Save vmorris/6e3eda1b3cb2f5dca274adff42add6d9 to your computer and use it in GitHub Desktop.
Save vmorris/6e3eda1b3cb2f5dca274adff42add6d9 to your computer and use it in GitHub Desktop.
Oct 08 12:43:36 juju-84a348-0 mongod.37017[5904]: [conn174] command juju.txns command: insert { insert: "txns", documents: [ { _id: ObjectId('57f8e9f8c5dca517a9e7b70b'), s: 1, o: [ { c: "leases", d: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:clock#application-leadership#", a: { $or: [ { writers.machine-0: { $lte: 1475930616730621000 } }, { writers.machine-0: { $exists: false } } ] }, u: { $set: { writers.machine-0: 1475930616730621000 } } }, { c: "leases", d: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:lease#application-leadership#rabbitmq-server#", a: { holder: "rabbitmq-server/0", expiry: 1475930646730277000, writer: "machine-0" }, u: { $set: { expiry: 1475930676730621000, writer: "machine-0" } } } ] } ], writeConcern: { getLastError: 1, j: true }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 158ms
Oct 08 12:43:38 juju-84a348-0 mongod.37017[5904]: [conn179] command juju.txns command: insert { insert: "txns", documents: [ { _id: ObjectId('57f8e9f9c5dca517a9e7b70f'), s: 1, o: [ { c: "machines", d: "68db2cf9-4982-4eb7-8837-280ce5efd84e:7", a: { life: { $ne: 2 } }, u: { $set: { passwordhash: "gIopWQnFGqdEnLyvrApWnLH9" } } } ] } ], writeConcern: { getLastError: 1, j: true }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 358ms
Oct 08 12:43:42 juju-84a348-0 mongod.37017[5904]: [conn179] command presence.presence.beings command: insert { insert: "presence.beings", documents: [ { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1", seq: 1, model-uuid: "68db2cf9-4982-4eb7-8837-280ce5efd84e", key: "m#1" } ], writeConcern: { getLastError: 1, j: true }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 351ms
Oct 08 12:43:44 juju-84a348-0 mongod.37017[5904]: [conn132] command presence.presence.beings command: insert { insert: "presence.beings", documents: [ { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:3", seq: 3, model-uuid: "68db2cf9-4982-4eb7-8837-280ce5efd84e", key: "u#ceph/1" } ], writeConcern: { getLastError: 1, j: true }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 172ms
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [thread1] WiredTiger (52) [1475930628:396760][5904:0x3ff927ff910], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 12288 bytes at offset 1048576: Invalid exchange
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [thread1] WiredTiger (52) [1475930628:397499][5904:0x3ff927ff910], checkpoint-server: checkpoint server error: Invalid exchange
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [thread1] WiredTiger (-31804) [1475930628:397518][5904:0x3ff927ff910], checkpoint-server: the process must exit and restart: WT_PANIC: WiredTiger library panic
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [thread1] Fatal Assertion 28558
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [thread1]
***aborting after fassert() failure
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [WTJournalFlusher] Fatal Assertion 28559
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [conn76] Fatal Assertion 28559
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [WTJournalFlusher]
***aborting after fassert() failure
Oct 08 12:43:48 juju-84a348-0 mongod.37017[5904]: [conn76]
***aborting after fassert() failure
Oct 08 12:49:17 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=killed, status=6/ABRT
Oct 08 12:49:17 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 12:49:17 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'signal'.
Oct 08 12:49:18 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 12:49:18 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 12:49:18 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 12:49:18 juju-84a348-0 mongod[16951]: 2016-10-08T12:49:18.368+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] MongoDB starting : pid=16951 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] db version v3.2.9
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] allocator: system
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] modules: none
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] build environment:
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] distarch: s390x
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] target_arch: s390x
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 12:49:18 juju-84a348-0 mongod.37017[16951]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (52) [1475930960:111874][16951:0x3ff97e6ab50], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 12288 bytes at offset 1048576: Invalid exchange
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (52) [1475930960:112044][16951:0x3ff97e6ab50], file:collection-22-3785058392042379666.wt, txn-recover: Recovery failed: Invalid exchange
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (52) [1475930960:172020][16951:0x3ff97e6ab50], file:collection-27-3785058392042379666.wt, connection: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 12288 bytes at offset 1048576: Invalid exchange
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (52) [1475930960:172076][16951:0x3ff97e6ab50], file:collection-27-3785058392042379666.wt, connection: Final close of file:collection-27-3785058392042379666.wt failed: Invalid exchange
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (0) [1475930960:176663][16951:0x3ff97e6ab50], connection: cache server: exiting with 178 pages in memory and 176 pages evicted
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (0) [1475930960:176696][16951:0x3ff97e6ab50], connection: cache server: exiting with 1747205 bytes in memory
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (0) [1475930960:176704][16951:0x3ff97e6ab50], connection: cache server: exiting with 1747205 bytes dirty and 2 pages dirty
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] WiredTiger (0) [1475930960:177086][16951:0x3ff97e6ab50], connection: Connection has open file handles: collection-27-3785058392042379666.wt
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16951]: [initandlisten] Assertion: 28595:52: Invalid exchange
Oct 08 12:49:20 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=100/n/a
Oct 08 12:49:20 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 12:49:20 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 12:49:20 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 12:49:20 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 12:49:20 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 12:49:20 juju-84a348-0 mongod[16954]: 2016-10-08T12:49:20.516+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] MongoDB starting : pid=16954 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] db version v3.2.9
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] allocator: system
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] modules: none
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] build environment:
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] distarch: s390x
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] target_arch: s390x
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 12:49:20 juju-84a348-0 mongod.37017[16954]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 12:49:21 juju-84a348-0 mongod.37017[16954]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 12:49:21 juju-84a348-0 mongod.37017[16954]: [initandlisten] The size storer reports that the oplog contains 1368747 records totaling to 388443254 bytes
Oct 08 12:49:21 juju-84a348-0 mongod.37017[16954]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 12:43:47:3b to determine where to place markers for truncation
Oct 08 12:49:21 juju-84a348-0 mongod.37017[16954]: [initandlisten] Taking 227 samples and assuming that each section of oplog contains approximately 60056 records totaling to 17043579 bytes
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 03:42:29:44
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 04:43:01:b
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 06:09:00:5
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 07:36:17:12
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 09:22:00:8
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 10:49:16:9
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 12:30:01:1
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 13:57:28:1b
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 15:11:59:13
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 16:40:46:4
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 17:44:28:1d
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 18:49:42:2
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 20:08:33:35
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 21:18:55:15
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 22:20:56:17
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 7 23:33:19:5
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 8 00:50:56:1
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 8 02:09:01:53
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 8 03:39:51:2
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 8 04:38:22:25
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 8 04:52:49:5
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Placing a marker at optime Oct 8 05:34:41:548
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten]
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten]
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten]
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten]
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] ** WARNING: soft rlimits too low. rlimits set to 20000 processes, 65000 files. Number of processes should be at least 32500 : 0.5 times number of files.
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten]
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/juju/db/diagnostic.data'
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [initandlisten] waiting for connections on port 37017 ssl
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] New replica set config in use: { _id: "juju", version: 1, protocolVersion: 1, members: [ { _id: 1, host: "10.113.186.232:37017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: { juju-machine-id: "0" }, slaveDelay: 0, votes: 1 } ], settings: { chainingAllowed: true, heartbeatIntervalMillis: 2000, heartbeatTimeoutSecs: 10, electionTimeoutMillis: 10000, getLastErrorModes: {}, getLastErrorDefaults: { w: 1, wtimeout: 0 }, replicaSetId: ObjectId('57f717c232b84bb4f772d375') } }
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] This node is 10.113.186.232:37017 in the config
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] transition to STARTUP2
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] Starting replication applier threads
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] transition to RECOVERING
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] transition to SECONDARY
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] conducting a dry run election to see if we could be elected
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] dry election run succeeded, running for election
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] election succeeded, assuming primary role in term 2
Oct 08 12:49:24 juju-84a348-0 mongod.37017[16954]: [ReplicationExecutor] transition to PRIMARY
Oct 08 12:49:25 juju-84a348-0 mongod.37017[16954]: [ftdc] Unclean full-time diagnostic data capture shutdown detected, found interim file, some metrics may have been lost. OK
Oct 08 12:49:25 juju-84a348-0 mongod.37017[16954]: [rsSync] transition to primary complete; database writes are now permitted
Oct 08 12:49:26 juju-84a348-0 mongod.37017[16954]: [conn62] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 12:49:26 juju-84a348-0 mongod.37017[16954]: [conn91] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 12:59:30 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:7 reslen:620 locks:{ Global: { acquireCount: { r: 16 } }, Database: { acquireCount: { r: 8 } }, Collection: { acquireCount: { r: 8 } } } protocol:op_query 182ms
Oct 08 13:00:24 juju-84a348-0 mongod.37017[16954]: [PeriodicTaskRunner] task: UnusedLockCleaner took: 152ms
Oct 08 13:01:29 juju-84a348-0 mongod.37017[16954]: [conn106] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8ee29c5dca517a9e7bc79'), t: 1475931689634527000, e: "ec6795d3-5f07-4133-8b14-dd1bb484a348", n: "machine-0", r: "2.0-rc3", m: "juju.worker.dependency", l: "engine.go:539", v: 5, x: ""disk-manager" manifold worker returned unexpected error: cannot list block devices: lsblk failed: fork/exec /bin/lsblk: cannot allocate memory" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 234ms
Oct 08 13:01:30 juju-84a348-0 mongod.37017[16954]: [conn90] command juju.leases command: find { find: "leases", filter: { type: "lease", namespace: "application-leadership", model-uuid: "ec6795d3-5f07-4133-8b14-dd1bb484a348" }, skip: 0 } planSummary: IXSCAN { model-uuid: 1, type: 1 } keysExamined:1 docsExamined:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:0 reslen:117 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 138ms
Oct 08 13:01:31 juju-84a348-0 mongod.37017[16954]: [conn118] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475931690" } update: { $set: { slot: 1475931690 }, $inc: { alive.0: 2305843009213693952 } } keysExamined:0 docsExamined:0 nMatched:1 nModified:1 upsert:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 181ms
Oct 08 13:01:31 juju-84a348-0 mongod.37017[16954]: [conn118] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475931690" }, u: { $set: { slot: 1475931690 }, $inc: { alive.0: 2305843009213693952 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:206 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 200ms
Oct 08 13:01:31 juju-84a348-0 mongod.37017[16954]: [conn120] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475931690" } update: { $set: { slot: 1475931690 }, $inc: { alive.0: 576460752303423488 } } keyUpdates:0 writeConflicts:1 exception: E11000 duplicate key error collection: presence.presence.pings index: _id_ dup key: { : "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475931690" } code:11000 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } 218ms
Oct 08 13:01:31 juju-84a348-0 mongod.37017[16954]: [conn120] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475931690" }, u: { $set: { slot: 1475931690 }, $inc: { alive.0: 576460752303423488 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:314 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_query 228ms
Oct 08 13:01:34 juju-84a348-0 mongod.37017[16954]: [conn62] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:262917477020 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:3 nreturned:10 reslen:1279 locks:{ Global: { acquireCount: { r: 8 } }, Database: { acquireCount: { r: 4 } }, Collection: { acquireCount: { r: 4 } } } protocol:op_query 317ms
Oct 08 13:01:34 juju-84a348-0 mongod.37017[16954]: [conn106] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8ee2cc5dca517a9e7bc7a'), t: 1475931692959675000, e: "ec6795d3-5f07-4133-8b14-dd1bb484a348", n: "machine-0", r: "2.0-rc3", m: "juju.worker.dependency", l: "engine.go:539", v: 5, x: ""disk-manager" manifold worker returned unexpected error: cannot list block devices: lsblk failed: fork/exec /bin/lsblk: cannot allocate memory" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 1021ms
Oct 08 13:01:36 juju-84a348-0 mongod.37017[16954]: [conn106] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8ee30c5dca517a9e7bc7b'), t: 1475931696057863000, e: "ec6795d3-5f07-4133-8b14-dd1bb484a348", n: "machine-0", r: "2.0-rc3", m: "juju.worker.dependency", l: "engine.go:539", v: 5, x: ""disk-manager" manifold worker returned unexpected error: cannot list block devices: lsblk failed: fork/exec /bin/lsblk: cannot allocate memory" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 120ms
Oct 08 13:01:37 juju-84a348-0 mongod.37017[16954]: [conn120] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475931690" } update: { $set: { slot: 1475931690 }, $inc: { alive.0: 4611686018427387904 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 210ms
Oct 08 13:01:37 juju-84a348-0 mongod.37017[16954]: [conn120] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475931690" }, u: { $set: { slot: 1475931690 }, $inc: { alive.0: 4611686018427387904 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 230ms
Oct 08 13:01:38 juju-84a348-0 mongod.37017[16954]: [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 0, after connections: 0, after extra_info: 7510, after globalLock: 7700, after locks: 7710, after network: 7720, after opcounters: 7720, after opcountersRepl: 7740, after repl: 7770, after security: 7780, after storageEngine: 7800, after wiredTiger: 7910, at end: 8290 }
Oct 08 13:01:39 juju-84a348-0 mongod.37017[16954]: [conn90] command juju.instanceData command: find { find: "instanceData", filter: { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:0" }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:402 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 572ms
Oct 08 13:01:43 juju-84a348-0 mongod.37017[16954]: [ftdc] serverStatus was very slow: { after basic: 0, after asserts: 0, after connections: 10, after extra_info: 2410, after globalLock: 2410, after locks: 2410, after network: 2410, after opcounters: 2410, after opcountersRepl: 2410, after repl: 2410, after security: 2410, after storageEngine: 2410, after wiredTiger: 2410, at end: 2410 }
Oct 08 13:02:30 juju-84a348-0 mongod.37017[16954]: [conn90] command juju.leases command: find { find: "leases", filter: { type: "lease", namespace: "application-leadership", model-uuid: "ec6795d3-5f07-4133-8b14-dd1bb484a348" }, skip: 0 } planSummary: IXSCAN { model-uuid: 1, type: 1 } keysExamined:1 docsExamined:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:0 reslen:117 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 194ms
Oct 08 13:02:39 juju-84a348-0 mongod.37017[16954]: [conn62] command juju.controllers command: find { find: "controllers", filter: { _id: "e" }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:401 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 154ms
Oct 08 13:03:19 juju-84a348-0 mongod.37017[16954]: [conn120] update presence.presence.pings query: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475931780" } update: { $set: { slot: 1475931780 }, $inc: { alive.0: 64 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 127ms
Oct 08 13:03:19 juju-84a348-0 mongod.37017[16954]: [conn120] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475931780" }, u: { $set: { slot: 1475931780 }, $inc: { alive.0: 64 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 131ms
Oct 08 13:03:22 juju-84a348-0 mongod.37017[16954]: [conn106] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8ee99c5dca517a9e7bc9d'), t: 1475931801984694000, e: "ec6795d3-5f07-4133-8b14-dd1bb484a348", n: "machine-0", r: "2.0-rc3", m: "juju.worker.dependency", l: "engine.go:539", v: 5, x: ""disk-manager" manifold worker returned unexpected error: cannot list block devices: lsblk failed: fork/exec /bin/lsblk: cannot allocate memory" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 137ms
Oct 08 13:03:26 juju-84a348-0 mongod.37017[16954]: [conn96] command admin.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{} protocol:op_query 140ms
Oct 08 13:03:26 juju-84a348-0 mongod.37017[16954]: [conn96] command presence.presence.pings command: find { find: "presence.pings", filter: { $or: [ { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475931780" }, { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475931750" } ] }, skip: 0 } planSummary: IXSCAN { _id: 1 } keysExamined:2 docsExamined:2 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:2 reslen:333 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 318ms
Oct 08 13:03:31 juju-84a348-0 mongod.37017[16954]: [conn96] command juju.leases command: find { find: "leases", filter: { type: "lease", namespace: "application-leadership", model-uuid: "ec6795d3-5f07-4133-8b14-dd1bb484a348" }, skip: 0 } planSummary: IXSCAN { model-uuid: 1, type: 1 } keysExamined:1 docsExamined:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:0 reslen:117 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 137ms
Oct 08 13:04:48 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:6 reslen:620 locks:{ Global: { acquireCount: { r: 14 } }, Database: { acquireCount: { r: 7 } }, Collection: { acquireCount: { r: 7 } } } protocol:op_query 186ms
Oct 08 13:07:12 juju-84a348-0 mongod.37017[16954]: [conn116] update presence.presence.pings query: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475932020" } update: { $set: { slot: 1475932020 }, $inc: { alive.0: 64 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 117ms
Oct 08 13:07:12 juju-84a348-0 mongod.37017[16954]: [conn116] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475932020" }, u: { $set: { slot: 1475932020 }, $inc: { alive.0: 64 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 204ms
Oct 08 13:09:49 juju-84a348-0 mongod.37017[16954]: [conn94] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:8 reslen:620 locks:{ Global: { acquireCount: { r: 18 } }, Database: { acquireCount: { r: 9 } }, Collection: { acquireCount: { r: 9 } } } protocol:op_query 628ms
Oct 08 13:12:34 juju-84a348-0 mongod.37017[16954]: [conn90] command juju.leases command: find { find: "leases", filter: { type: "lease", namespace: "application-leadership", model-uuid: "ec6795d3-5f07-4133-8b14-dd1bb484a348" }, skip: 0 } planSummary: IXSCAN { model-uuid: 1, type: 1 } keysExamined:1 docsExamined:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:2 nreturned:0 reslen:117 locks:{ Global: { acquireCount: { r: 6 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } protocol:op_query 130ms
Oct 08 13:14:51 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:3 reslen:620 locks:{ Global: { acquireCount: { r: 8 } }, Database: { acquireCount: { r: 4 } }, Collection: { acquireCount: { r: 4 } } } protocol:op_query 414ms
Oct 08 13:14:51 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: collStats { collStats: "logs", scale: 1048576 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:18695 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 527ms
Oct 08 13:17:10 juju-84a348-0 mongod.37017[16954]: [conn127] update presence.presence.pings query: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475932620" } update: { $set: { slot: 1475932620 }, $inc: { alive.0: 64 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 103ms
Oct 08 13:17:10 juju-84a348-0 mongod.37017[16954]: [conn127] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475932620" }, u: { $set: { slot: 1475932620 }, $inc: { alive.0: 64 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 209ms
Oct 08 13:19:52 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:2 reslen:620 locks:{ Global: { acquireCount: { r: 6 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } protocol:op_query 143ms
Oct 08 13:19:52 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: collStats { collStats: "logs", scale: 1048576 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:18695 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 127ms
Oct 08 13:24:52 juju-84a348-0 mongod.37017[16954]: [conn94] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:8 reslen:620 locks:{ Global: { acquireCount: { r: 18 } }, Database: { acquireCount: { r: 9 } }, Collection: { acquireCount: { r: 9 } } } protocol:op_query 250ms
Oct 08 13:24:53 juju-84a348-0 mongod.37017[16954]: [conn94] command logs.logs command: collStats { collStats: "logs", scale: 1048576 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:18695 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 240ms
Oct 08 13:29:54 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:8 reslen:620 locks:{ Global: { acquireCount: { r: 18 } }, Database: { acquireCount: { r: 9 } }, Collection: { acquireCount: { r: 9 } } } protocol:op_query 366ms
Oct 08 13:29:54 juju-84a348-0 mongod.37017[16954]: [conn90] command logs.logs command: collStats { collStats: "logs", scale: 1048576 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:18695 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 132ms
Oct 08 13:34:57 juju-84a348-0 mongod.37017[16954]: [conn94] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:9 reslen:620 locks:{ Global: { acquireCount: { r: 20 } }, Database: { acquireCount: { r: 10 } }, Collection: { acquireCount: { r: 10 } } } protocol:op_query 393ms
Oct 08 13:34:58 juju-84a348-0 mongod.37017[16954]: [conn94] command logs.logs command: collStats { collStats: "logs", scale: 1048576 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:18695 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 202ms
Oct 08 13:39:49 juju-84a348-0 mongod.37017[16954]: [conn112] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f2c5dca517a9e7b703') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 105ms
Oct 08 13:39:49 juju-84a348-0 mongod.37017[16954]: [conn62] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:262731156196 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:10 reslen:1279 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 114ms
Oct 08 13:40:00 juju-84a348-0 mongod.37017[16954]: [conn87] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:7 reslen:620 locks:{ Global: { acquireCount: { r: 16 } }, Database: { acquireCount: { r: 8 } }, Collection: { acquireCount: { r: 8 } } } protocol:op_query 169ms
Oct 08 13:40:01 juju-84a348-0 mongod.37017[16954]: [conn87] command logs.logs command: collStats { collStats: "logs", scale: 1048576 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:18695 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 233ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn129] command presence.presence.pings command: find { find: "presence.pings", filter: { $or: [ { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" }, { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934330" } ] }, skip: 0 } planSummary: IXSCAN { _id: 1 } keysExamined:1 docsExamined:0 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:129 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 110ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn118] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" } update: { $set: { slot: 1475934360 }, $inc: { alive.0: 1152921504606846976 } } keysExamined:0 docsExamined:0 nMatched:1 nModified:1 upsert:1 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 306ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn87] command admin.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{} protocol:op_query 327ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn120] command juju.leases command: find { find: "leases", filter: { type: "lease", namespace: "application-leadership", model-uuid: "ec6795d3-5f07-4133-8b14-dd1bb484a348" }, skip: 0 } planSummary: IXSCAN { model-uuid: 1, type: 1 } keysExamined:1 docsExamined:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:117 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 334ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn113] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 333ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn128] update presence.presence.pings query: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475934360" } update: { $set: { slot: 1475934360 }, $inc: { alive.0: 32 } } keysExamined:0 docsExamined:0 nMatched:1 nModified:1 upsert:1 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 307ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn118] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" }, u: { $set: { slot: 1475934360 }, $inc: { alive.0: 1152921504606846976 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:206 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 663ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn128] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475934360" }, u: { $set: { slot: 1475934360 }, $inc: { alive.0: 32 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:206 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 663ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn105] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 332ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn112] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f2c5dca517a9e7b703') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 333ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn86] command admin.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{} protocol:op_query 590ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn104] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f6c5dca517a9e7b708') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 333ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn107] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 333ms
Oct 08 13:46:13 juju-84a348-0 mongod.37017[16954]: [conn108] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 333ms
Oct 08 13:46:14 juju-84a348-0 mongod.37017[16954]: [conn103] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 649ms
Oct 08 13:46:14 juju-84a348-0 mongod.37017[16954]: [conn111] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea02c5dca517a9e7b930') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 333ms
Oct 08 13:46:14 juju-84a348-0 mongod.37017[16954]: [conn90] command juju.instanceData command: find { find: "instanceData", filter: { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:0" }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:402 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 718ms
Oct 08 13:46:14 juju-84a348-0 mongod.37017[16954]: [conn98] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:263607337010 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:10 reslen:1279 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 770ms
Oct 08 13:46:14 juju-84a348-0 mongod.37017[16954]: [conn125] command presence.presence.pings command: find { find: "presence.pings", filter: { $or: [ { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475934360" }, { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475934330" } ] }, skip: 0 } planSummary: IXSCAN { _id: 1 } keysExamined:0 docsExamined:0 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:129 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 766ms
Oct 08 13:46:14 juju-84a348-0 mongod.37017[16954]: [conn91] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:264489420560 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:10 reslen:1279 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 1628ms
Oct 08 13:46:14 juju-84a348-0 mongod.37017[16954]: [conn109] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8f8a5c5dca517a9e7bf78'), t: 1475934247975961000, e: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0", n: "unit-rabbitmq-server-0", r: "2.0-rc3", m: "juju.api", l: "apiclient.go:562", v: 5, x: "health ping timed out after 30s" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 987ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn101] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:265034408472 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:10 reslen:1279 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 1712ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn62] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:264135694351 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:10 reslen:1279 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 1987ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn126] command presence.presence.pings command: find { find: "presence.pings", filter: { $or: [ { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475934360" }, { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475934330" } ] }, skip: 0 } planSummary: IXSCAN { _id: 1 } keysExamined:1 docsExamined:0 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:129 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2027ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn99] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2027ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn88] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:6 reslen:620 locks:{ Global: { acquireCount: { r: 14 } }, Database: { acquireCount: { r: 7 } }, Collection: { acquireCount: { r: 7 } } } protocol:op_query 2204ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn114] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f0c5dca517a9e7b701') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:589 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2277ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn96] command local.system.replset command: find { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: COLLSCAN keysExamined:0 docsExamined:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:1 nreturned:1 reslen:582 locks:{ Global: { acquireCount: { r: 4 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_query 185ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn99] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea02c5dca517a9e7b930') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 161ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn89] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea02c5dca517a9e7b930') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2279ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn100] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f0c5dca517a9e7b701') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:589 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2279ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn102] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f0c5dca517a9e7b701') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:589 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2279ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn106] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8f8a5c5dca517a9e7bf79'), t: 1475934373149703000, e: "ec6795d3-5f07-4133-8b14-dd1bb484a348", n: "machine-0", r: "2.0-rc3", m: "juju.apiserver.common", l: "resource.go:118", v: 5, x: "error stopping *apiserver.pingTimeout resource: ping timeout" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 2274ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn122] update presence.presence.pings query: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475934360" } update: { $set: { slot: 1475934360 }, $inc: { alive.0: 64 } } keyUpdates:0 writeConflicts:0 exception: E11000 duplicate key error collection: presence.presence.pings index: _id_ dup key: { : "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475934360" } code:11000 numYields:1 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } 2311ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn122] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475934360" }, u: { $set: { slot: 1475934360 }, $inc: { alive.0: 64 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:314 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } protocol:op_query 2363ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn110] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f6c5dca517a9e7b708') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2279ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn115] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" } update: { $set: { slot: 1475934360 }, $inc: { alive.0: 288230376151711744 } } keyUpdates:0 writeConflicts:0 exception: E11000 duplicate key error collection: presence.presence.pings index: _id_ dup key: { : "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" } code:11000 numYields:1 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } 2309ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn115] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" }, u: { $set: { slot: 1475934360 }, $inc: { alive.0: 288230376151711744 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:314 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } protocol:op_query 2400ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn123] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" } update: { $set: { slot: 1475934360 }, $inc: { alive.0: 576460752303423488 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:1 numYields:2 locks:{ Global: { acquireCount: { r: 4, w: 4 } }, Database: { acquireCount: { w: 4 } }, Collection: { acquireCount: { w: 3 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 2364ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn123] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475934360" }, u: { $set: { slot: 1475934360 }, $inc: { alive.0: 576460752303423488 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 4, w: 4 } }, Database: { acquireCount: { w: 4 } }, Collection: { acquireCount: { w: 3 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 2415ms
Oct 08 13:46:15 juju-84a348-0 mongod.37017[16954]: [conn92] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8f8a5c5dca517a9e7bf77'), t: 1475934243983331000, e: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0", n: "machine-0", r: "2.0-rc3", m: "juju.api", l: "apiclient.go:562", v: 5, x: "health ping timed out after 30s" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 1695ms
Oct 08 13:47:39 juju-84a348-0 mongod.37017[16954]: [conn131] command juju.txns command: find { find: "txns", filter: { s: { $in: [ 1, 2, 4 ] } }, skip: 0 } planSummary: COLLSCAN cursorid:257983971319 keysExamined:0 docsExamined:6406 keyUpdates:0 writeConflicts:0 numYields:237 nreturned:101 reslen:45592 locks:{ Global: { acquireCount: { r: 476 } }, Database: { acquireCount: { r: 238 } }, Collection: { acquireCount: { r: 238 } } } protocol:op_query 7632ms
Oct 08 13:48:20 juju-84a348-0 mongod.37017[16954]: [conn135] command juju.instanceData command: find { find: "instanceData", filter: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:0" }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:402 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 475ms
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [thread1] WiredTiger (52) [1475934503:90283][16954:0x3ff97fff910], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [thread1] WiredTiger (52) [1475934503:112076][16954:0x3ff97fff910], checkpoint-server: checkpoint server error: Invalid exchange
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [thread1] WiredTiger (-31804) [1475934503:112110][16954:0x3ff97fff910], checkpoint-server: the process must exit and restart: WT_PANIC: WiredTiger library panic
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [thread1] Fatal Assertion 28558
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [thread1]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn135] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn131] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn105] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn131]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn135]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn105]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn89] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn89]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn139] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn110] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn107] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn88] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn100] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn102] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn102]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [WTJournalFlusher] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn110]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn139]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn114] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn113] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn103] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn111] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn108] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn104] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn107]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn88]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn100]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn112] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn96] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn99] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn138] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [WTJournalFlusher]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn114]
***aborting after fassert() failure
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn101] Fatal Assertion 28559
Oct 08 13:48:23 juju-84a348-0 mongod.37017[16954]: [conn101]
***aborting after fassert() failure
Oct 08 13:48:24 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=killed, status=6/ABRT
Oct 08 13:48:24 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 13:48:24 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'signal'.
Oct 08 13:48:25 juju-84a348-0 mongod[17241]: 2016-10-08T13:48:25.081+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] MongoDB starting : pid=17241 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 13:48:24 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] db version v3.2.9
Oct 08 13:48:24 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 13:48:24 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] allocator: system
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] modules: none
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] build environment:
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] distarch: s390x
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] target_arch: s390x
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 13:48:25 juju-84a348-0 mongod.37017[17241]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 13:48:30 juju-84a348-0 mongod.37017[17241]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 13:48:30 juju-84a348-0 mongod.37017[17241]: [initandlisten] The size storer reports that the oplog contains 1372784 records totaling to 389910691 bytes
Oct 08 13:48:30 juju-84a348-0 mongod.37017[17241]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 13:48:22:3 to determine where to place markers for truncation
Oct 08 13:48:30 juju-84a348-0 mongod.37017[17241]: [initandlisten] Taking 228 samples and assuming that each section of oplog contains approximately 60007 records totaling to 17043738 bytes
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 03:42:36:35
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 04:48:14:41
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 06:12:40:1
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 07:38:28:15
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 09:27:25:8
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 10:53:06:2
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 12:18:28:1e
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 14:02:40:1
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 15:14:50:6
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 16:30:22:b
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 17:48:35:6
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 18:53:20:4
Oct 08 13:48:31 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 19:59:15:2
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 21:23:21:4
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 22:23:15:7
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 7 23:23:09:6
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 8 00:55:45:5
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 8 02:12:56:8
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 8 03:33:51:e
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 8 04:38:32:21
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 8 04:55:07:13
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Placing a marker at optime Oct 8 05:10:27:87
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten]
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten]
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten]
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten]
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] ** WARNING: soft rlimits too low. rlimits set to 20000 processes, 65000 files. Number of processes should be at least 32500 : 0.5 times number of files.
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten]
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/juju/db/diagnostic.data'
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] New replica set config in use: { _id: "juju", version: 1, protocolVersion: 1, members: [ { _id: 1, host: "10.113.186.232:37017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: { juju-machine-id: "0" }, slaveDelay: 0, votes: 1 } ], settings: { chainingAllowed: true, heartbeatIntervalMillis: 2000, heartbeatTimeoutSecs: 10, electionTimeoutMillis: 10000, getLastErrorModes: {}, getLastErrorDefaults: { w: 1, wtimeout: 0 }, replicaSetId: ObjectId('57f717c232b84bb4f772d375') } }
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] This node is 10.113.186.232:37017 in the config
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] transition to STARTUP2
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [initandlisten] waiting for connections on port 37017 ssl
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] Starting replication applier threads
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] transition to RECOVERING
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] transition to SECONDARY
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] conducting a dry run election to see if we could be elected
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] dry election run succeeded, running for election
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] election succeeded, assuming primary role in term 3
Oct 08 13:48:32 juju-84a348-0 mongod.37017[17241]: [ReplicationExecutor] transition to PRIMARY
Oct 08 13:48:33 juju-84a348-0 mongod.37017[17241]: [ftdc] Unclean full-time diagnostic data capture shutdown detected, found interim file, some metrics may have been lost. OK
Oct 08 13:48:33 juju-84a348-0 mongod.37017[17241]: [rsSync] transition to primary complete; database writes are now permitted
Oct 08 14:06:17 juju-84a348-0 mongod.37017[17241]: [conn10] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:06:18 juju-84a348-0 mongod.37017[17241]: [conn14] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:12:32 juju-84a348-0 mongod.37017[17241]: [conn25] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f0c5dca517a9e7b701') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:589 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 247ms
Oct 08 14:12:32 juju-84a348-0 mongod.37017[17241]: [conn20] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea02c5dca517a9e7b930') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 265ms
Oct 08 14:12:33 juju-84a348-0 mongod.37017[17241]: [conn35] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f6c5dca517a9e7b708') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 208ms
Oct 08 14:12:33 juju-84a348-0 mongod.37017[17241]: [conn20] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 194ms
Oct 08 14:12:33 juju-84a348-0 mongod.37017[17241]: [conn50] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea02c5dca517a9e7b930') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 190ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn24] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f2c5dca517a9e7b703') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 559ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn34] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 184ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn27] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 155ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn24] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f2c5dca517a9e7b703') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 144ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [PeriodicTaskRunner] task: UnusedLockCleaner took: 1482ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn18] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f0c5dca517a9e7b701') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:589 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 281ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn21] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 394ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn11] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:263165133385 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:3 nreturned:10 reslen:1343 locks:{ Global: { acquireCount: { r: 8 } }, Database: { acquireCount: { r: 4 } }, Collection: { acquireCount: { r: 4 } } } protocol:op_query 238ms
Oct 08 14:12:34 juju-84a348-0 mongod.37017[17241]: [conn29] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8fed0c5dca543b2c95ee3'), t: 1475935952649168000, e: "ec6795d3-5f07-4133-8b14-dd1bb484a348", n: "machine-0", r: "2.0-rc3", m: "juju.worker.dependency", l: "engine.go:539", v: 5, x: ""disk-manager" manifold worker returned unexpected error: cannot list block devices: lsblk failed: fork/exec /bin/lsblk: cannot allocate memory" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 740ms
Oct 08 14:12:35 juju-84a348-0 mongod.37017[17241]: [ftdc] serverStatus was very slow: { after basic: 10, after asserts: 10, after connections: 10, after extra_info: 2700, after globalLock: 2700, after locks: 2700, after network: 2700, after opcounters: 2700, after opcountersRepl: 2710, after repl: 2720, after security: 2720, after storageEngine: 2760, after wiredTiger: 2790, at end: 2810 }
Oct 08 14:14:18 juju-84a348-0 mongod.37017[17241]: [conn13] command admin.$cmd command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{} protocol:op_query 129ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn26] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 208ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn17] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea02c5dca517a9e7b930') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 205ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn19] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:264229691403 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:10 reslen:1343 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 210ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn27] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 210ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn10] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 210ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn16] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:264150830854 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:10 reslen:1343 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 198ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn11] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:263382973940 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:10 reslen:1343 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 208ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn50] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 209ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn20] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 209ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn25] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f6c5dca517a9e7b708') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 209ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn35] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9ecc5dca517a9e7b6fd') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 214ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn14] command juju.txns.log command: find { find: "txns.log", sort: { $natural: -1 }, skip: 0, batchSize: 10 } planSummary: COLLSCAN cursorid:262127502469 keysExamined:0 docsExamined:10 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:10 reslen:1343 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 198ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn34] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea00c5dca517a9e7b7be') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:333 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 209ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn21] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f0c5dca517a9e7b701') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:589 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 209ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn28] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f0c5dca517a9e7b701') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:589 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 228ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn29] command logs.logs command: insert { insert: "logs", documents: [ { _id: ObjectId('57f8ff51c5dca543b2c95f04'), t: 1475936081047939000, e: "ec6795d3-5f07-4133-8b14-dd1bb484a348", n: "machine-0", r: "2.0-rc3", m: "juju.worker.dependency", l: "engine.go:539", v: 5, x: ""disk-manager" manifold worker returned unexpected error: cannot list block devices: lsblk failed: fork/exec /bin/lsblk: cannot allocate memory" } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 321ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn18] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8ea02c5dca517a9e7b930') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:618 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 144ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn47] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" } update: { $set: { slot: 1475936070 }, $inc: { alive.1: 32 } } keysExamined:0 docsExamined:0 nMatched:1 nModified:1 upsert:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 289ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn49] update presence.presence.pings query: { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475936070" } update: { $set: { slot: 1475936070 }, $inc: { alive.0: 256 } } keysExamined:0 docsExamined:0 nMatched:1 nModified:1 upsert:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 292ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn48] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" } update: { $set: { slot: 1475936070 }, $inc: { alive.1: 64 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 304ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn51] update presence.presence.pings query: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475936070" } update: { $set: { slot: 1475936070 }, $inc: { alive.0: 1024 } } keysExamined:0 docsExamined:0 nMatched:1 nModified:1 upsert:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 198ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn48] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" }, u: { $set: { slot: 1475936070 }, $inc: { alive.1: 64 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 315ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn49] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475936070" }, u: { $set: { slot: 1475936070 }, $inc: { alive.0: 256 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:206 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 386ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn46] update presence.presence.pings query: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475936070" } update: { $set: { slot: 1475936070 }, $inc: { alive.0: 512 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 208ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn52] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" } update: { $set: { slot: 1475936070 }, $inc: { alive.1: 8 } } keyUpdates:0 writeConflicts:1 exception: E11000 duplicate key error collection: presence.presence.pings index: _id_ dup key: { : "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" } code:11000 numYields:1 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } 210ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn51] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475936070" }, u: { $set: { slot: 1475936070 }, $inc: { alive.0: 1024 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:206 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 207ms
Oct 08 14:14:41 juju-84a348-0 mongod.37017[17241]: [conn46] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:1475936070" }, u: { $set: { slot: 1475936070 }, $inc: { alive.0: 512 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 320ms
Oct 08 14:14:42 juju-84a348-0 mongod.37017[17241]: [conn47] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" }, u: { $set: { slot: 1475936070 }, $inc: { alive.1: 32 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:206 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 386ms
Oct 08 14:14:42 juju-84a348-0 mongod.37017[17241]: [conn52] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" }, u: { $set: { slot: 1475936070 }, $inc: { alive.1: 8 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:314 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } protocol:op_query 211ms
Oct 08 14:14:42 juju-84a348-0 mongod.37017[17241]: [conn45] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" } update: { $set: { slot: 1475936070 }, $inc: { alive.1: 4 } } keyUpdates:0 writeConflicts:1 exception: E11000 duplicate key error collection: presence.presence.pings index: _id_ dup key: { : "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" } code:11000 numYields:1 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } 319ms
Oct 08 14:14:42 juju-84a348-0 mongod.37017[17241]: [conn45] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475936070" }, u: { $set: { slot: 1475936070 }, $inc: { alive.1: 4 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:314 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } protocol:op_query 963ms
Oct 08 14:14:42 juju-84a348-0 mongod.37017[17241]: [conn24] command juju.txns command: find { find: "txns", filter: { _id: ObjectId('57f8e9f2c5dca517a9e7b703') }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:331 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 157ms
Oct 08 14:16:20 juju-84a348-0 mongod.37017[17241]: [conn58] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:5 reslen:620 locks:{ Global: { acquireCount: { r: 12 } }, Database: { acquireCount: { r: 6 } }, Collection: { acquireCount: { r: 6 } } } protocol:op_query 104ms
Oct 08 14:21:21 juju-84a348-0 mongod.37017[17241]: [conn12] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:5 reslen:620 locks:{ Global: { acquireCount: { r: 12 } }, Database: { acquireCount: { r: 6 } }, Collection: { acquireCount: { r: 6 } } } protocol:op_query 152ms
Oct 08 14:30:04 juju-84a348-0 mongod.37017[17241]: [conn38] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475937000" } update: { $set: { slot: 1475937000 }, $inc: { alive.1: 4 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:1 numYields:1 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 269ms
Oct 08 14:30:04 juju-84a348-0 mongod.37017[17241]: [conn55] update presence.presence.pings query: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475937000" } update: { $set: { slot: 1475937000 }, $inc: { alive.1: 64 } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:2 numYields:2 locks:{ Global: { acquireCount: { r: 4, w: 4 } }, Database: { acquireCount: { w: 4 } }, Collection: { acquireCount: { w: 3 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 292ms
Oct 08 14:30:04 juju-84a348-0 mongod.37017[17241]: [conn55] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475937000" }, u: { $set: { slot: 1475937000 }, $inc: { alive.1: 64 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 4, w: 4 } }, Database: { acquireCount: { w: 4 } }, Collection: { acquireCount: { w: 3 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 293ms
Oct 08 14:30:04 juju-84a348-0 mongod.37017[17241]: [conn38] command presence.$cmd command: update { update: "presence.pings", updates: [ { q: { _id: "68db2cf9-4982-4eb7-8837-280ce5efd84e:1475937000" }, u: { $set: { slot: 1475937000 }, $inc: { alive.1: 4 } }, upsert: true } ], writeConcern: { getLastError: 1, j: true }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:115 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 292ms
Oct 08 14:31:22 juju-84a348-0 mongod.37017[17241]: [conn12] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:8 reslen:620 locks:{ Global: { acquireCount: { r: 18 } }, Database: { acquireCount: { r: 9 } }, Collection: { acquireCount: { r: 9 } } } protocol:op_query 204ms
Oct 08 14:37:05 juju-84a348-0 mongod.37017[17241]: [conn45] command presence.presence.beings command: find { find: "presence.beings", filter: { model-uuid: "ec6795d3-5f07-4133-8b14-dd1bb484a348" }, skip: 0 } planSummary: COLLSCAN keysExamined:0 docsExamined:312 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:5 nreturned:9 reslen:1345 locks:{ Global: { acquireCount: { r: 12 } }, Database: { acquireCount: { r: 6 } }, Collection: { acquireCount: { r: 6 } } } protocol:op_query 135ms
Oct 08 14:37:07 juju-84a348-0 mongod.37017[17241]: [conn24] SSL: error:1408F119:SSL routines:SSL3_GET_RECORD:decryption failed or bad record mac
Oct 08 14:42:19 juju-84a348-0 mongod.37017[17241]: [conn13] command logs.logs command: distinct { distinct: "logs", key: "e" } keyUpdates:0 writeConflicts:0 numYields:7 reslen:620 locks:{ Global: { acquireCount: { r: 16 } }, Database: { acquireCount: { r: 8 } }, Collection: { acquireCount: { r: 8 } } } protocol:op_query 223ms
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [thread1] WiredTiger (52) [1475937777:172958][17241:0x3ff977ff910], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [thread1] WiredTiger (52) [1475937777:189642][17241:0x3ff977ff910], checkpoint-server: checkpoint server error: Invalid exchange
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [thread1] WiredTiger (-31804) [1475937777:189656][17241:0x3ff977ff910], checkpoint-server: the process must exit and restart: WT_PANIC: WiredTiger library panic
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [thread1] Fatal Assertion 28558
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [thread1]
***aborting after fassert() failure
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [WTJournalFlusher] Fatal Assertion 28559
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [WTJournalFlusher]
***aborting after fassert() failure
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [conn50] Fatal Assertion 28559
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [conn50]
***aborting after fassert() failure
Oct 08 14:42:57 juju-84a348-0 mongod.37017[17241]: [conn17] Fatal Assertion 28559
Oct 08 14:42:58 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=killed, status=6/ABRT
Oct 08 14:42:58 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:42:58 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'signal'.
Oct 08 14:42:58 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:42:58 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:42:59 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:42:59 juju-84a348-0 mongod[17505]: 2016-10-08T14:42:59.495+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] MongoDB starting : pid=17505 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] db version v3.2.9
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] allocator: system
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] modules: none
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] build environment:
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] distarch: s390x
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] target_arch: s390x
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:42:59 juju-84a348-0 mongod.37017[17505]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (52) [1475937784:235166][17505:0x3ffb666ab50], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (52) [1475937784:237231][17505:0x3ffb666ab50], file:collection-22-3785058392042379666.wt, txn-recover: Recovery failed: Invalid exchange
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (52) [1475937784:256095][17505:0x3ffb666ab50], file:collection-27-3785058392042379666.wt, connection: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (52) [1475937784:256119][17505:0x3ffb666ab50], file:collection-27-3785058392042379666.wt, connection: Final close of file:collection-27-3785058392042379666.wt failed: Invalid exchange
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (0) [1475937784:298705][17505:0x3ffb666ab50], connection: cache server: exiting with 52 pages in memory and 50 pages evicted
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (0) [1475937784:298742][17505:0x3ffb666ab50], connection: cache server: exiting with 90731 bytes in memory
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (0) [1475937784:298749][17505:0x3ffb666ab50], connection: cache server: exiting with 90731 bytes dirty and 2 pages dirty
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] WiredTiger (0) [1475937784:299088][17505:0x3ffb666ab50], connection: Connection has open file handles: collection-27-3785058392042379666.wt
Oct 08 14:43:04 juju-84a348-0 mongod.37017[17505]: [initandlisten] Assertion: 28595:52: Invalid exchange
Oct 08 14:43:04 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=100/n/a
Oct 08 14:43:04 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:43:04 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:43:04 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:43:04 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:43:05 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:43:05 juju-84a348-0 mongod[17508]: 2016-10-08T14:43:05.071+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] MongoDB starting : pid=17508 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] db version v3.2.9
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] allocator: system
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] modules: none
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] build environment:
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] distarch: s390x
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] target_arch: s390x
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:43:05 juju-84a348-0 mongod.37017[17508]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:43:10 juju-84a348-0 mongod.37017[17508]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:43:10 juju-84a348-0 mongod.37017[17508]: [initandlisten] The size storer reports that the oplog contains 1378136 records totaling to 391613297 bytes
Oct 08 14:43:10 juju-84a348-0 mongod.37017[17508]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:42:56:c to determine where to place markers for truncation
Oct 08 14:43:10 juju-84a348-0 mongod.37017[17508]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59979 records totaling to 17043727 bytes
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 03:42:31:97
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 04:27:43:3
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 06:01:30:1
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 07:37:03:1
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 09:06:24:6
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 10:41:51:a
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 12:17:17:4
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 13:42:00:d
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 15:04:58:10
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 16:29:28:6
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 17:35:52:5
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 18:43:51:8
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 20:00:15:12
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 21:17:28:1
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 22:17:38:7
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 7 23:23:46:6
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 8 00:48:58:2f
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 8 02:04:41:2f
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 8 03:34:40:f2
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 8 04:38:17:16
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 8 04:50:14:1b
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] Placing a marker at optime Oct 8 05:10:25:244
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten]
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten]
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten]
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten]
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten] ** WARNING: soft rlimits too low. rlimits set to 20000 processes, 65000 files. Number of processes should be at least 32500 : 0.5 times number of files.
Oct 08 14:43:11 juju-84a348-0 mongod.37017[17508]: [initandlisten]
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/juju/db/diagnostic.data'
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [initandlisten] waiting for connections on port 37017 ssl
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] New replica set config in use: { _id: "juju", version: 1, protocolVersion: 1, members: [ { _id: 1, host: "10.113.186.232:37017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: { juju-machine-id: "0" }, slaveDelay: 0, votes: 1 } ], settings: { chainingAllowed: true, heartbeatIntervalMillis: 2000, heartbeatTimeoutSecs: 10, electionTimeoutMillis: 10000, getLastErrorModes: {}, getLastErrorDefaults: { w: 1, wtimeout: 0 }, replicaSetId: ObjectId('57f717c232b84bb4f772d375') } }
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] This node is 10.113.186.232:37017 in the config
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] transition to STARTUP2
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] Starting replication applier threads
Oct 08 14:43:12 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] transition to RECOVERING
Oct 08 14:43:13 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] transition to SECONDARY
Oct 08 14:43:13 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] conducting a dry run election to see if we could be elected
Oct 08 14:43:13 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] dry election run succeeded, running for election
Oct 08 14:43:13 juju-84a348-0 mongod.37017[17508]: [ftdc] Unclean full-time diagnostic data capture shutdown detected, found interim file, some metrics may have been lost. OK
Oct 08 14:43:13 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] election succeeded, assuming primary role in term 4
Oct 08 14:43:13 juju-84a348-0 mongod.37017[17508]: [ReplicationExecutor] transition to PRIMARY
Oct 08 14:43:13 juju-84a348-0 mongod.37017[17508]: [rsSync] transition to primary complete; database writes are now permitted
Oct 08 14:43:14 juju-84a348-0 mongod.37017[17508]: [conn14] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:43:15 juju-84a348-0 mongod.37017[17508]: [conn26] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:43:20 juju-84a348-0 mongod.37017[17508]: [conn30] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:43:25 juju-84a348-0 mongod.37017[17508]: [conn34] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:43:29 juju-84a348-0 mongod.37017[17508]: [conn40] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:43:34 juju-84a348-0 mongod.37017[17508]: [conn45] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:43:38 juju-84a348-0 mongod.37017[17508]: [conn50] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:44:09 juju-84a348-0 mongod.37017[17508]: [thread1] WiredTiger (52) [1475937849:966588][17508:0x3ff8f7ff910], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:44:09 juju-84a348-0 mongod.37017[17508]: [thread1] WiredTiger (52) [1475937849:980120][17508:0x3ff8f7ff910], checkpoint-server: checkpoint server error: Invalid exchange
Oct 08 14:44:09 juju-84a348-0 mongod.37017[17508]: [thread1] WiredTiger (-31804) [1475937849:980144][17508:0x3ff8f7ff910], checkpoint-server: the process must exit and restart: WT_PANIC: WiredTiger library panic
Oct 08 14:44:09 juju-84a348-0 mongod.37017[17508]: [thread1] Fatal Assertion 28558
Oct 08 14:44:09 juju-84a348-0 mongod.37017[17508]: [thread1]
***aborting after fassert() failure
Oct 08 14:44:09 juju-84a348-0 mongod.37017[17508]: [conn44] Fatal Assertion 28559
Oct 08 14:44:10 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=killed, status=6/ABRT
Oct 08 14:44:10 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:44:10 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'signal'.
Oct 08 14:44:10 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:44:10 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:44:10 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:44:10 juju-84a348-0 mongod[17647]: 2016-10-08T14:44:10.881+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] MongoDB starting : pid=17647 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] db version v3.2.9
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] allocator: system
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] modules: none
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] build environment:
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] distarch: s390x
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] target_arch: s390x
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:44:10 juju-84a348-0 mongod.37017[17647]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (52) [1475937852:598378][17647:0x3ffb776ab50], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (52) [1475937852:618713][17647:0x3ffb776ab50], file:collection-11-3785058392042379666.wt, txn-recover: Recovery failed: Invalid exchange
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (52) [1475937852:648003][17647:0x3ffb776ab50], file:collection-27-3785058392042379666.wt, connection: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (52) [1475937852:648040][17647:0x3ffb776ab50], file:collection-27-3785058392042379666.wt, connection: Final close of file:collection-27-3785058392042379666.wt failed: Invalid exchange
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (0) [1475937852:664917][17647:0x3ffb776ab50], connection: cache server: exiting with 58 pages in memory and 56 pages evicted
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (0) [1475937852:664945][17647:0x3ffb776ab50], connection: cache server: exiting with 48907 bytes in memory
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (0) [1475937852:664953][17647:0x3ffb776ab50], connection: cache server: exiting with 48907 bytes dirty and 2 pages dirty
Oct 08 14:44:12 juju-84a348-0 mongod.37017[17647]: [initandlisten] WiredTiger (0) [1475937852:665420][17647:0x3ffb776ab50], connection: Connection has open file handles: collection-27-3785058392042379666.wt
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17647]: [initandlisten] Assertion: 28595:52: Invalid exchange
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17647]: [initandlisten] exception in initAndListen: 28595 52: Invalid exchange, terminating
Oct 08 14:44:13 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=100/n/a
Oct 08 14:44:13 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:44:13 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:44:13 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:44:13 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:44:13 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:44:13 juju-84a348-0 mongod[17650]: 2016-10-08T14:44:13.801+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] MongoDB starting : pid=17650 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] db version v3.2.9
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] allocator: system
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] modules: none
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] build environment:
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] distarch: s390x
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] target_arch: s390x
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:44:13 juju-84a348-0 mongod.37017[17650]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:44:16 juju-84a348-0 mongod.37017[17650]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:44:16 juju-84a348-0 mongod.37017[17650]: [initandlisten] The size storer reports that the oplog contains 1378136 records totaling to 391613297 bytes
Oct 08 14:44:16 juju-84a348-0 mongod.37017[17650]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:44:09:3 to determine where to place markers for truncation
Oct 08 14:44:16 juju-84a348-0 mongod.37017[17650]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59979 records totaling to 17043727 bytes
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 03:42:41:1b
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 04:39:30:16
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 06:12:53:14
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 07:38:58:2d
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 09:18:30:12
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 10:53:14:c
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 12:19:06:2d
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 13:53:58:3a
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 15:14:58:3
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 16:31:04:2
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 17:41:30:9
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 18:56:16:2
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 20:09:31:6
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 21:18:59:c
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 22:25:58:12
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 7 23:34:21:4
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 8 00:51:06:3
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 8 02:16:15:a
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 8 03:41:29:9
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 8 04:38:23:f
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 8 04:58:15:d
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] Placing a marker at optime Oct 8 05:34:41:ee4
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten]
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten]
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten]
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] ** We suggest setting it to 'never'
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten]
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten] ** WARNING: soft rlimits too low. rlimits set to 20000 processes, 65000 files. Number of processes should be at least 32500 : 0.5 times number of files.
Oct 08 14:44:17 juju-84a348-0 mongod.37017[17650]: [initandlisten]
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/juju/db/diagnostic.data'
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] New replica set config in use: { _id: "juju", version: 1, protocolVersion: 1, members: [ { _id: 1, host: "10.113.186.232:37017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: { juju-machine-id: "0" }, slaveDelay: 0, votes: 1 } ], settings: { chainingAllowed: true, heartbeatIntervalMillis: 2000, heartbeatTimeoutSecs: 10, electionTimeoutMillis: 10000, getLastErrorModes: {}, getLastErrorDefaults: { w: 1, wtimeout: 0 }, replicaSetId: ObjectId('57f717c232b84bb4f772d375') } }
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] This node is 10.113.186.232:37017 in the config
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] transition to STARTUP2
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] Starting replication applier threads
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [initandlisten] waiting for connections on port 37017 ssl
Oct 08 14:44:18 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] transition to RECOVERING
Oct 08 14:44:19 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] transition to SECONDARY
Oct 08 14:44:19 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] conducting a dry run election to see if we could be elected
Oct 08 14:44:19 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] dry election run succeeded, running for election
Oct 08 14:44:19 juju-84a348-0 mongod.37017[17650]: [ftdc] Unclean full-time diagnostic data capture shutdown detected, found interim file, some metrics may have been lost. OK
Oct 08 14:44:19 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] election succeeded, assuming primary role in term 5
Oct 08 14:44:19 juju-84a348-0 mongod.37017[17650]: [ReplicationExecutor] transition to PRIMARY
Oct 08 14:44:20 juju-84a348-0 mongod.37017[17650]: [rsSync] transition to primary complete; database writes are now permitted
Oct 08 14:44:33 juju-84a348-0 mongod.37017[17650]: [conn8] command admin.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} protocol:op_query 337ms
Oct 08 14:44:33 juju-84a348-0 mongod.37017[17650]: [conn12] command admin.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} protocol:op_query 248ms
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn3] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn11] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 3878ms
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn14] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 3598ms
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn1] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2779ms
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn9] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2644ms
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn15] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2371ms
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn4] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2409ms
Oct 08 14:44:34 juju-84a348-0 mongod.37017[17650]: [conn7] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:155 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 1323ms
Oct 08 14:44:39 juju-84a348-0 mongod.37017[17650]: [conn15] command juju.leases command: find { find: "leases", filter: { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:clock#singular-controller#" }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:3342 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 1274ms
Oct 08 14:51:09 juju-84a348-0 mongod.37017[17650]: [conn9] command admin.system.users command: saslContinue { saslContinue: 1, conversationId: 1, mechanism: "SCRAM-SHA-1", payload: BinData(0, ) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:78 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 181ms
Oct 08 14:54:00 juju-84a348-0 mongod.37017[17650]: [conn1] command juju.units command: find { find: "units", filter: { _id: "df12dbc2-cbd0-4f76-8b1d-c6af996004c0:rabbitmq-server/0" }, skip: 0, limit: 1, batchSize: 1, singleBatch: true } planSummary: IDHACK keysExamined:1 docsExamined:1 idhack:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:675 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 113ms
Oct 08 14:54:36 juju-84a348-0 mongod.37017[17650]: [conn4] command presence.presence.pings command: find { find: "presence.pings", filter: { $or: [ { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475937840" }, { _id: "ec6795d3-5f07-4133-8b14-dd1bb484a348:1475937810" } ] }, skip: 0 } planSummary: IXSCAN { _id: 1 } keysExamined:2 docsExamined:2 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:2 nreturned:2 reslen:333 locks:{ Global: { acquireCount: { r: 6 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } protocol:op_query 129ms
Oct 08 14:55:51 juju-84a348-0 mongod.37017[17650]: [conn60] Unauthorized: not authorized on local to execute command { find: "system.replset", skip: 0, limit: 1, batchSize: 1, singleBatch: true }
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [thread1] WiredTiger (52) [1475938581:607016][17650:0x3ff87fff910], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [thread1] WiredTiger (52) [1475938581:609343][17650:0x3ff87fff910], checkpoint-server: checkpoint server error: Invalid exchange
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [thread1] WiredTiger (-31804) [1475938581:609362][17650:0x3ff87fff910], checkpoint-server: the process must exit and restart: WT_PANIC: WiredTiger library panic
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [thread1] Fatal Assertion 28558
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [thread1]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn56] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn67] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn70] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn67]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn56]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn70]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn72] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn65] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn63] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn53] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn40] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn79] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn74] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn69] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn61] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn77] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn82] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn81] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn75] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn75]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn68] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn71] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn72]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn65]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn12] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn63]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn53]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn40]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn79]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn74]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn69]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn61]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn77]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn82]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn81]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn19] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn68]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn71]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn12]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [conn19]
***aborting after fassert() failure
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [WTJournalFlusher] Fatal Assertion 28559
Oct 08 14:56:21 juju-84a348-0 mongod.37017[17650]: [WTJournalFlusher]
***aborting after fassert() failure
Oct 08 14:56:22 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=killed, status=6/ABRT
Oct 08 14:56:22 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:22 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'signal'.
Oct 08 14:56:22 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:22 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:22 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:22 juju-84a348-0 mongod[17811]: 2016-10-08T14:56:22.733+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] MongoDB starting : pid=17811 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] db version v3.2.9
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] allocator: system
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] modules: none
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] build environment:
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] distarch: s390x
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] target_arch: s390x
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:22 juju-84a348-0 mongod.37017[17811]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (52) [1475938586:332319][17811:0x3ffa1feab50], file:collection-27-3785058392042379666.wt, WT_SESSION.checkpoint: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (52) [1475938586:339220][17811:0x3ffa1feab50], file:collection-43-3785058392042379666.wt, txn-recover: Recovery failed: Invalid exchange
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (52) [1475938586:400584][17811:0x3ffa1feab50], file:collection-27-3785058392042379666.wt, connection: /var/lib/juju/db/collection-27-3785058392042379666.wt: handle-write: pwrite: failed to write 8192 bytes at offset 1044480: Invalid exchange
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (52) [1475938586:400623][17811:0x3ffa1feab50], file:collection-27-3785058392042379666.wt, connection: Final close of file:collection-27-3785058392042379666.wt failed: Invalid exchange
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (0) [1475938586:409253][17811:0x3ffa1feab50], connection: cache server: exiting with 37 pages in memory and 35 pages evicted
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (0) [1475938586:409286][17811:0x3ffa1feab50], connection: cache server: exiting with 53855 bytes in memory
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (0) [1475938586:409294][17811:0x3ffa1feab50], connection: cache server: exiting with 53855 bytes dirty and 2 pages dirty
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] WiredTiger (0) [1475938586:409390][17811:0x3ffa1feab50], connection: Connection has open file handles: collection-27-3785058392042379666.wt
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] Assertion: 28595:52: Invalid exchange
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17811]: [initandlisten] exception in initAndListen: 28595 52: Invalid exchange, terminating
Oct 08 14:56:26 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=100/n/a
Oct 08 14:56:26 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:26 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:26 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:26 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:26 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:26 juju-84a348-0 mongod[17814]: 2016-10-08T14:56:26.809+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] MongoDB starting : pid=17814 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] db version v3.2.9
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] allocator: system
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] modules: none
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] build environment:
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] distarch: s390x
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] target_arch: s390x
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:26 juju-84a348-0 mongod.37017[17814]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:28 juju-84a348-0 mongod.37017[17814]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:28 juju-84a348-0 mongod.37017[17814]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 08 14:56:28 juju-84a348-0 mongod.37017[17814]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 08 14:56:28 juju-84a348-0 mongod.37017[17814]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 08 14:56:28 juju-84a348-0 mongod.37017[17814]: [initandlisten] WiredTiger (5) [1475938588:555850][17814:0x3ff9b56ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 08 14:56:28 juju-84a348-0 mongod.37017[17814]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 08 14:56:28 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:28 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:28 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:28 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:28 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:29 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:29 juju-84a348-0 mongod[17828]: 2016-10-08T14:56:29.083+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] MongoDB starting : pid=17828 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] db version v3.2.9
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] allocator: system
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] modules: none
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] build environment:
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] distarch: s390x
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] target_arch: s390x
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:29 juju-84a348-0 mongod.37017[17828]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:31 juju-84a348-0 mongod.37017[17828]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:31 juju-84a348-0 mongod.37017[17828]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 08 14:56:31 juju-84a348-0 mongod.37017[17828]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 08 14:56:31 juju-84a348-0 mongod.37017[17828]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 08 14:56:31 juju-84a348-0 mongod.37017[17828]: [initandlisten] WiredTiger (5) [1475938591:592341][17828:0x3ffaadeab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 08 14:56:31 juju-84a348-0 mongod.37017[17828]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 08 14:56:32 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:32 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:32 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:32 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:32 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:32 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:32 juju-84a348-0 mongod[17842]: 2016-10-08T14:56:32.309+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] MongoDB starting : pid=17842 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] db version v3.2.9
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] allocator: system
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] modules: none
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] build environment:
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] distarch: s390x
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] target_arch: s390x
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:32 juju-84a348-0 mongod.37017[17842]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:33 juju-84a348-0 mongod.37017[17842]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:33 juju-84a348-0 mongod.37017[17842]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 08 14:56:33 juju-84a348-0 mongod.37017[17842]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 08 14:56:33 juju-84a348-0 mongod.37017[17842]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 08 14:56:33 juju-84a348-0 mongod.37017[17842]: [initandlisten] WiredTiger (5) [1475938593:203028][17842:0x3ffbb66ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 08 14:56:33 juju-84a348-0 mongod.37017[17842]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 08 14:56:33 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:33 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:33 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:33 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:33 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:34 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:34 juju-84a348-0 mongod[17856]: 2016-10-08T14:56:34.089+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] MongoDB starting : pid=17856 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] db version v3.2.9
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] allocator: system
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] modules: none
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] build environment:
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] distarch: s390x
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] target_arch: s390x
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:34 juju-84a348-0 mongod.37017[17856]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:34 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:34 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:34 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:35 juju-84a348-0 mongod[17870]: 2016-10-08T14:56:35.323+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:35 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:35 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:35 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] MongoDB starting : pid=17870 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] db version v3.2.9
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] allocator: system
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] modules: none
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] build environment:
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] distarch: s390x
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] target_arch: s390x
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:35 juju-84a348-0 mongod.37017[17870]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17870]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17870]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17870]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17870]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17870]: [initandlisten] WiredTiger (5) [1475938596:545097][17870:0x3ff86d6ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17870]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 08 14:56:36 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:36 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:36 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:36 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:36 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:36 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:36 juju-84a348-0 mongod[17884]: 2016-10-08T14:56:36.836+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] MongoDB starting : pid=17884 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] db version v3.2.9
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] allocator: system
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] modules: none
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] build environment:
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] distarch: s390x
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] target_arch: s390x
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:36 juju-84a348-0 mongod.37017[17884]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:37 juju-84a348-0 mongod.37017[17884]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:37 juju-84a348-0 mongod.37017[17884]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 08 14:56:37 juju-84a348-0 mongod.37017[17884]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 08 14:56:37 juju-84a348-0 mongod.37017[17884]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 08 14:56:37 juju-84a348-0 mongod.37017[17884]: [initandlisten] WiredTiger (5) [1475938597:662939][17884:0x3ffb4aeab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 08 14:56:37 juju-84a348-0 mongod.37017[17884]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 08 14:56:37 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:37 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:37 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:37 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:37 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:38 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:38 juju-84a348-0 mongod[17898]: 2016-10-08T14:56:38.026+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] MongoDB starting : pid=17898 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] db version v3.2.9
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] allocator: system
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] modules: none
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] build environment:
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] distarch: s390x
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] target_arch: s390x
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] WiredTiger (5) [1475938598:824018][17898:0x3ffa686ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 08 14:56:38 juju-84a348-0 mongod.37017[17898]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 08 14:56:38 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:38 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:38 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:38 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:38 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:39 juju-84a348-0 systemd[1]: Started juju state database.
Oct 08 14:56:39 juju-84a348-0 mongod[17912]: 2016-10-08T14:56:39.025+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] MongoDB starting : pid=17912 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] db version v3.2.9
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] allocator: system
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] modules: none
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] build environment:
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] distarch: s390x
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] target_arch: s390x
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] WiredTiger (5) [1475938599:835015][17912:0x3ffbd6eab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 08 14:56:39 juju-84a348-0 mongod.37017[17912]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 08 14:56:39 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 08 14:56:39 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 08 14:56:39 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 08 14:56:39 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 08 14:56:39 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 08 14:56:39 juju-84a348-0 systemd[1]: juju-db.service: Start request repeated too quickly.
Oct 08 14:56:39 juju-84a348-0 systemd[1]: Failed to start juju state database.
Oct 10 15:14:43 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:14:43 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:14:43 juju-84a348-0 mongod[20565]: 2016-10-10T15:14:43.478+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] MongoDB starting : pid=20565 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] db version v3.2.9
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] allocator: system
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] modules: none
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] build environment:
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] distarch: s390x
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] target_arch: s390x
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] WiredTiger (5) [1476112483:858406][20565:0x3ff917eab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:14:43 juju-84a348-0 mongod.37017[20565]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:14:43 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:14:43 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:14:43 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:14:44 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:14:44 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:14:44 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:14:44 juju-84a348-0 mongod[20579]: 2016-10-10T15:14:44.285+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] MongoDB starting : pid=20579 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] db version v3.2.9
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] allocator: system
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] modules: none
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] build environment:
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] distarch: s390x
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] target_arch: s390x
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] WiredTiger (5) [1476112484:674360][20579:0x3ff877eab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:14:44 juju-84a348-0 mongod.37017[20579]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:14:44 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:14:44 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:14:44 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:14:44 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:14:44 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:14:45 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:14:45 juju-84a348-0 mongod[20593]: 2016-10-10T15:14:45.085+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] MongoDB starting : pid=20593 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] db version v3.2.9
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] allocator: system
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] modules: none
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] build environment:
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] distarch: s390x
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] target_arch: s390x
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] WiredTiger (5) [1476112485:459897][20593:0x3ff9a46ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20593]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:14:45 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:14:45 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:14:45 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:14:45 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:14:45 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:14:45 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:14:45 juju-84a348-0 mongod[20607]: 2016-10-10T15:14:45.835+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] MongoDB starting : pid=20607 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] db version v3.2.9
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] allocator: system
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] modules: none
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] build environment:
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] distarch: s390x
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] target_arch: s390x
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:14:45 juju-84a348-0 mongod.37017[20607]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20607]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20607]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20607]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20607]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20607]: [initandlisten] WiredTiger (5) [1476112486:216045][20607:0x3ffa5b6ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20607]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:14:46 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:14:46 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:14:46 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:14:46 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:14:46 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:14:46 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:14:46 juju-84a348-0 mongod[20621]: 2016-10-10T15:14:46.545+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] MongoDB starting : pid=20621 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] db version v3.2.9
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] allocator: system
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] modules: none
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] build environment:
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] distarch: s390x
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] target_arch: s390x
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] WiredTiger (5) [1476112486:922222][20621:0x3ff819eab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:14:46 juju-84a348-0 mongod.37017[20621]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:14:46 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:14:46 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:14:46 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:14:47 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:14:47 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:14:47 juju-84a348-0 systemd[1]: juju-db.service: Start request repeated too quickly.
Oct 10 15:14:47 juju-84a348-0 systemd[1]: Failed to start juju state database.
Oct 10 15:16:14 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:16:19 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:16:19 juju-84a348-0 mongod[20657]: 2016-10-10T15:16:19.938+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] MongoDB starting : pid=20657 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] db version v3.2.9
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] allocator: system
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] modules: none
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] build environment:
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] distarch: s390x
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] target_arch: s390x
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:16:19 juju-84a348-0 mongod.37017[20657]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20657]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20657]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20657]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20657]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20657]: [initandlisten] WiredTiger (5) [1476112580:327056][20657:0x3ff8f36ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20657]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:16:20 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:16:20 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:16:20 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:16:20 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:16:20 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:16:20 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:16:20 juju-84a348-0 mongod[20671]: 2016-10-10T15:16:20.545+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] MongoDB starting : pid=20671 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] db version v3.2.9
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] allocator: system
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] modules: none
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] build environment:
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] distarch: s390x
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] target_arch: s390x
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] WiredTiger (5) [1476112580:924122][20671:0x3ff87b6ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:16:20 juju-84a348-0 mongod.37017[20671]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:16:20 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:16:20 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:16:20 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:16:21 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:16:21 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:16:21 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:16:21 juju-84a348-0 mongod[20685]: 2016-10-10T15:16:21.316+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] MongoDB starting : pid=20685 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] db version v3.2.9
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] allocator: system
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] modules: none
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] build environment:
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] distarch: s390x
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] target_arch: s390x
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] WiredTiger (5) [1476112581:687656][20685:0x3ffb65eab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:16:21 juju-84a348-0 mongod.37017[20685]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:16:21 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:16:21 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:16:21 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:16:21 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:16:21 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:16:22 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:16:22 juju-84a348-0 mongod[20699]: 2016-10-10T15:16:22.036+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] MongoDB starting : pid=20699 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] db version v3.2.9
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] allocator: system
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] modules: none
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] build environment:
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] distarch: s390x
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] target_arch: s390x
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] WiredTiger (5) [1476112582:493348][20699:0x3ff8ce6ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20699]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:16:22 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:16:22 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:16:22 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:16:22 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:16:22 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:16:22 juju-84a348-0 systemd[1]: Started juju state database.
Oct 10 15:16:22 juju-84a348-0 mongod[20713]: 2016-10-10T15:16:22.826+0000 W CONTROL [main] No SSL certificate validation can be performed since no CA file has been provided; please specify an sslCAFile parameter
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] MongoDB starting : pid=20713 port=37017 dbpath=/var/lib/juju/db 64-bit host=juju-84a348-0
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] db version v3.2.9
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] allocator: system
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] modules: none
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] build environment:
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] distarch: s390x
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] target_arch: s390x
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] options: { net: { ipv6: true, port: 37017, ssl: { PEMKeyFile: "/var/lib/juju/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" } }, replication: { oplogSizeMB: 1024, replSet: "juju" }, security: { authorization: "enabled", keyFile: "/var/lib/juju/shared-secret" }, storage: { dbPath: "/var/lib/juju/db", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "syslog", quiet: true } }
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] Detected unclean shutdown - /var/lib/juju/db/mongod.lock is not empty.
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] Recovering data from the last clean checkpoint.
Oct 10 15:16:22 juju-84a348-0 mongod.37017[20713]: [initandlisten] wiredtiger_open config: create,cache_size=22G,session_max=20000,eviction=(threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
Oct 10 15:16:23 juju-84a348-0 mongod.37017[20713]: [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Oct 10 15:16:23 juju-84a348-0 mongod.37017[20713]: [initandlisten] The size storer reports that the oplog contains 1378374 records totaling to 391729955 bytes
Oct 10 15:16:23 juju-84a348-0 mongod.37017[20713]: [initandlisten] Sampling from the oplog between Oct 7 03:34:26:1 and Oct 8 14:56:18:2 to determine where to place markers for truncation
Oct 10 15:16:23 juju-84a348-0 mongod.37017[20713]: [initandlisten] Taking 229 samples and assuming that each section of oplog contains approximately 59971 records totaling to 17043586 bytes
Oct 10 15:16:23 juju-84a348-0 mongod.37017[20713]: [initandlisten] WiredTiger (5) [1476112583:118688][20713:0x3ff8fa6ab50], file:collection-4-3785058392042379666.wt, WT_CURSOR.next: /var/lib/juju/db/collection-4-3785058392042379666.wt: handle-read: pread: failed to read 8192 bytes at offset 140378112: Input/output error
Oct 10 15:16:23 juju-84a348-0 mongod.37017[20713]: [initandlisten] Invariant failure: advanceRet resulted in status UnknownError: 5: Input/output error at src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp 674
Oct 10 15:16:23 juju-84a348-0 systemd[1]: juju-db.service: Main process exited, code=exited, status=14/n/a
Oct 10 15:16:23 juju-84a348-0 systemd[1]: juju-db.service: Unit entered failed state.
Oct 10 15:16:23 juju-84a348-0 systemd[1]: juju-db.service: Failed with result 'exit-code'.
Oct 10 15:16:23 juju-84a348-0 systemd[1]: juju-db.service: Service hold-off time over, scheduling restart.
Oct 10 15:16:23 juju-84a348-0 systemd[1]: Stopped juju state database.
Oct 10 15:16:23 juju-84a348-0 systemd[1]: juju-db.service: Start request repeated too quickly.
Oct 10 15:16:23 juju-84a348-0 systemd[1]: Failed to start juju state database.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment