using multiprocess to run upsert, get duplicated records in collection

[taopier]

db version v2.0.5

using strom, the threads(also in different process) run code : myDB("mytable").update(DBObject("key1" -> new ObjectId(myKey), "key2" -> coKey), myUpdates, true, false, WriteConcern.SAFE)

and my storm log as following (node1 and node2 is different machine, the last two columns is using :System.currentTimeMillis(),Thread.currentThread() ):
on node1: storm-0.8.1/logs/worker-6711.log:2012-09-14 11:18:11 STDIO [INFO] 1347592691476 Thread[Thread-16,5,main]
on node2: storm-0.8.1/logs/worker-6705.log:2012-09-14 11:18:11 STDIO [INFO] 1347592691456 Thread[Thread-24,5,main]

there is no record in mytable meets the query DBObject("key1" -> new ObjectId(myKey), "key2" -> coKey) before they run,
and after they run, there will exist exactly two same records, which I think is quite the opposite of what I know of the meaning of upsert = true.

although the possibility is quite low, say, I use storm to upsert around 6w records, and 4 duplicated appeared, most of their behavior is as what we expected.
I run my code several times, and each time the duplicated record is random both in content or number, say (2-10)

the following is mongostat:
insert  query update delete getmore command flushes mapped  vsize    res faults locked % idx miss %     qr|qw   ar|aw  netIn netOut  conn       time 
     0     50     86      0       0      43       0  1.03g  1.78g   451m      0       40          0       3|2   31|20    63k    10k   152   11:27:06 
     0     68     77      0       0      53       0  1.03g  1.78g   451m      0     24.9          0      10|6   41|15    59k    12k   152   11:27:07 
     0     53     67      0       0      46       0  1.03g  1.78g   451m      0     30.7          0      0|12   39|16    46k    11k   152   11:27:08 
     0     38     63      0       0      39       0  1.03g  1.78g   451m      0     39.2          0      2|20   27|23    40k     9k   152   11:27:09 
     0     47     78      0       0      53       0  1.03g  1.78g   451m      0     28.3          0      4|13   35|16    46k    11k   152   11:27:10 
     0     56     97      0       0      48       0  1.03g  1.78g   451m      0     37.3          0     12|15   32|23    66k    11k   152   11:27:11 
     0     51     63      0       0      36       0  1.03g  1.78g   451m      0     39.8          0      12|2   36|17    51k     9k   152   11:27:12 
     0     68     93      0       0      69       0  1.03g  1.78g   451m      0     18.8          0     15|13   38|15    60k    15k   152   11:27:13 
     0     49     70      0       0      30       0  1.03g  1.78g   452m      3     42.6          0      1|27   25|30    53k     9k   152   11:27:14 
     0     42     72      0       0      48       0  1.03g  1.78g   452m      0     37.3          0     13|15   37|15    54k     9k   152   11:27:15 

and the related log in db log:
Fri Sep 14 11:18:11 [conn5772] update myDB.mytable query: { key1: ObjectId('4e9d248f5270152c35000007'), key2: "1" } update: { field1: "field1", field2: "1.31", updated_at: "2012-09-14 11:18:10", key1: ObjectId('4e9d248f5270152c35000007'), key2: "1" } upsert:1 795ms
Fri Sep 14 11:18:11 [conn5737] update myDB.mytable query: { key1: ObjectId('4e9d248f5270152c35000007'), key2: "1" } update: { field1: "field1", field2: "1.31", updated_at: "2012-09-14 11:18:10", key1: ObjectId('4e9d248f5270152c35000007'), key2: "1" } upsert:1 704ms


I'm wondering whether this is a bug or what, any idea?

[taopier]

does anybody have any idea?

"I use storm to upsert around 60000 records, and 4 duplicated appeared, most of their behavior is as what we expected."

在 2012年9月17日星期一UTC+8上午10时31分04秒，taopier写道：

db version v2.0.5

using strom, the threads(also in different process) run code : myDB("mytable").update(DBObject("key1" -> new ObjectId(myKey), "key2" -> coKey), myUpdates, true, false, WriteConcern.SAFE)

and my storm log as following (node1 and node2 is different machine, the last two columns is using :System.currentTimeMillis(),Thread.currentThread() ):
on node1: storm-0.8.1/logs/worker-6711.log:2012-09-14 11:18:11 STDIO [INFO] 1347592691476 Thread[Thread-16,5,main]
on node2: storm-0.8.1/logs/worker-6705.log:2012-09-14 11:18:11 STDIO [INFO] 1347592691456 Thread[Thread-24,5,main]

there is no record in mytable meets the query DBObject("key1" -> new ObjectId(myKey), "key2" -> coKey) before they run,
and after they run, there will exist exactly two same records, which I think is quite the opposite of what I know of the meaning of upsert = true.

although the possibility is quite low, say, I use storm to upsert around 60000 records, and 4 duplicated appeared, most of their behavior is as what we expected.