[SERVER-12112] Running authSchemaUpgradeStep on one mongos and then on another with an out of date cache fails Created: 16/Dec/13  Updated: 11/Jul/16  Resolved: 18/Dec/13

Status: Closed
Project: Core Server
Component/s: Security, Sharding
Affects Version/s: 2.5.4
Fix Version/s: 2.5.5

Type: Bug Priority: Major - P3
Reporter: Valeri Karpov Assignee: Spencer Brody (Inactive)
Resolution: Done Votes: 0
Labels: 26qa
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

OSX


Attachments: File sharded_upgrade_concurrent_multiple_mongos.js     File x509_shrd_upgrade.js    
Issue Links:
Related
Operating System: ALL
Participants:

 Description   

Error messages look like:

 m30998| 2013-12-16T11:01:22.605-0500 [conn2] Auth schema upgrade processing schema version 1 users from database admin
 m30998| 2013-12-16T11:01:22.605-0500 [conn2] Assertion: 13111:wrong type for field (0) 3 != 2
 m30998| 2013-12-16T11:01:22.610-0500 [conn2] 0x10042569b 0x1003e29a2 0x1003d039f 0x1003d047d 0x1002b6460 0x10009b704 0x10003a063 0x10002d378 0x10002c8a7 0x1000b68c9 0x10009d25b 0x100111bd0 0x10033839b 0x1002d7f68 0x100358aed 0x100337a27 0x100002d9f 0x1003eac11 0x1004559c5 0x7fff8c3e8772 
 m30998|  0   mongos-26                           0x000000010042569b _ZN5mongo15printStackTraceERSo + 43
 m30998|  1   mongos-26                           0x00000001003e29a2 _ZN5mongo10logContextEPKc + 114
 m30998|  2   mongos-26                           0x00000001003d039f _ZN5mongo11msgassertedEiPKc + 255
 m30998|  3   mongos-26                           0x00000001003d047d _ZN5mongo11msgassertedEiRKSs + 29
 m30998|  4   mongos-26                           0x00000001002b6460 _ZNK5mongo11BSONElement3chkEi + 800
 m30998|  5   mongos-26                           0x000000010009b704 _ZN5mongo12_GLOBAL__N_118upgradeProcessUserEPNS_25AuthzManagerExternalStateERKNS_10StringDataERKNS_7BSONObjES8_ + 4164
 m30998|  6   mongos-26                           0x000000010003a063 _ZN5mongo20DBClientFunConvertorclERNS_27DBClientCursorBatchIteratorE + 231
 m30998|  7   mongos-26                           0x000000010002d378 _ZN5mongo18DBClientConnection5queryEN5boost8functionIFvRNS_27DBClientCursorBatchIteratorEEEERKSsNS_5QueryEPKNS_7BSONObjEi + 686
 m30998|  8   mongos-26                           0x000000010002c8a7 _ZN5mongo12DBClientBase5queryEN5boost8functionIFvRKNS_7BSONObjEEEERKSsNS_5QueryEPS4_i + 397
 m30998|  9   mongos-26                           0x00000001000b68c9 _ZN5mongo31AuthzManagerExternalStateMongos5queryERKNS_15NamespaceStringERKNS_7BSONObjES6_RKN5boost8functionIFvS6_EEE + 429
 m30998|  10  mongos-26                           0x000000010009d25b _ZN5mongo20AuthorizationManager17upgradeSchemaStepERKNS_7BSONObjEPb + 3035
 m30998|  11  mongos-26                           0x0000000100111bd0 _ZN5mongo24CmdAuthSchemaUpgradeStep3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb + 290
 m30998|  12  mongos-26                           0x000000010033839b _ZN5mongo7Command22execCommandClientBasicEPS0_RNS_11ClientBasicEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb + 681
 m30998|  13  mongos-26                           0x00000001002d7f68 _ZN5mongo7Command20runAgainstRegisteredEPKcRNS_7BSONObjERNS_14BSONObjBuilderEi + 678
 m30998|  14  mongos-26                           0x0000000100358aed _ZN5mongo14SingleStrategy7queryOpERNS_7RequestE + 1851
 m30998|  15  mongos-26                           0x0000000100337a27 _ZN5mongo7Request7processEi + 1249
 m30998|  16  mongos-26                           0x0000000100002d9f _ZN5mongo21ShardedMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE + 141
 m30998|  17  mongos-26                           0x00000001003eac11 _ZN5mongo17PortMessageServer17handleIncomingMsgEPv + 1681
 m30998|  18  mongos-26                           0x00000001004559c5 thread_proxy + 229
 m30998|  19  libsystem_c.dylib                   0x00007fff8c3e8772 _pthread_start + 327
 m29000| 2013-12-16T11:01:22.610-0500 [conn5] end connection 127.0.0.1:49616 (5 connections now open)
 m30998| 2013-12-16T11:01:22.610-0500 [conn2] Detected bad connection created at 1387209680357032 microSec, clearing pool for localhost:29000 of 0 connections
 m30998| 2013-12-16T11:01:22.610-0500 [conn2] Auth schema upgraded failed with Unknown error code wrong type for field (0) 3 != 2
 m30998| 2013-12-16T11:01:22.611-0500 [conn2] distributed lock 'authorizationData/specter.local:30998:1387209680:16807' unlocked. 
sh834| #2: undefined
 m29000| 2013-12-16T11:01:22.612-0500 [initandlisten] connection accepted from 127.0.0.1:49632 #14 (6 connections now open)
 m29000| 2013-12-16T11:01:22.612-0500 [conn14]  authenticate db: local { authenticate: 1, nonce: "xxx", user: "__system", key: "xxx" }
 m30998| 2013-12-16T11:01:22.613-0500 [conn2] warning: Could not fetch updated user privilege information for admin@admin; continuing to use old information.  Reason is AuthSchemaIncompatible User documents with schema version 1 must have a "pwd" field.

See attached script for what I'm doing to get this error.



 Comments   
Comment by Githook User [ 18/Dec/13 ]

Author:

{u'username': u'stbrody', u'name': u'Spencer T Brody', u'email': u'spencer@10gen.com'}

Message: SERVER-12112 Invalidate user cache before starting auth schema upgrade
Branch: master
https://github.com/mongodb/mongo/commit/0ec3c8d281bf634aba07b73f1ff88aa68ec46a6a

Comment by Valeri Karpov [ 18/Dec/13 ]

Nice catch Spencer.

Comment by Spencer Brody (Inactive) [ 18/Dec/13 ]

The problem seems to be not that the upgrades are running at the same time, the distlock prevents that.
This can be reproduced more simply by running the upgrade to completion on one mongos, then doing the upgrade on another mongos that still has the old schema version cached in memory. The fix is to just invalidate the user cache before starting the upgrade.

Comment by Valeri Karpov [ 18/Dec/13 ]

The other script that's required

Generated at Thu Feb 08 03:27:38 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.