Load and update fail issue #1271
Comments
|
Did you start with an empty MongoDB instance before the load? Can you provide the workload file you used and the exact command lines for both the load and run(s)? The output does not seem to match the workloada file from git. |
|
The workload config file i used is; recordcount=1000 and the exact command path I used is; C:/ycsb 0.14.0>python27/python.exe bin/ycsb load mongodb-async -s -P workloads/workloada > outputLoad.txt |
|
That is the command for the 'load'. What command did you use for the 'run'? The output you posted appears to be from a different workload because the percent of read (942) to update (58) operations is not 50/50 (or 0.5/0.5). It looks more like a 'workloadb' (0.95/0.5) A 'run' has to be done after a compatible 'load'. The easiest way to ensure the load is compatible is to use the same workload file. workloada and workloadb should be compatible as long as the record count is the same in both. Can you post the output from the 'load'? |
|
this is the command for the run bin/ycsb run mongodb-async -s -P workloads/workloada > outputLoad.txt |
|
The logs are not matching the information you posted. Can you run the workloads again and this time name the logs something different e.g., outputWorkloadALoad.txt and outputWorkloadARun.txt) and post all of the following:
I am starting to think that maybe something happened during the load phase. Rob. |
|
I load the workload, I name the log as outputWorkloadfAload.txt and this the output mongo connection created with mongodb://localhost:27017/ycsb?w=1 |
|
I also ran the workload, and name the log as outputWorkloadfARun.txt and this the output mongo connection created with mongodb://localhost:27017/ycsb?w=1 |
|
But as you can see, for the load I have zero insert and one insert fail operation then lantency insert fail also. I also have both update and read fail during the run stage. |
|
Is MongoDB running on the same machine that you are running the ycsb on? Can you connect via the mongo shell to localhost:27017? |
|
yes mongodb server is started and the mongob shell is connected, this is the output i also got mongo client connection created with mongodb://localhost:27017/ycsb?w= |
|
This is the path I use C:\YCSB-14\ycsb-0.14.0>c:\Python27\python.exe bin\ycsb load mongodb -s -P workloads\workloada -p mongodb.url=mongodb://localhost:27017/ycsb?=0>outputworkloadALoad.txt |
|
The fact that there is only a single insert operation and it failed means the client is probably not connecting. Is there any logging to the screen with an error message. There should have been something written to stderr. |
|
Here is the path i use to connect to the server This is the output C:\Program Files\MongoDB\Server\4.0\bin>mongod 2019-01-07T02:47:54.390-0800 I CONTROL [initandlisten] ** addresses it should serve responses from, or with --bind_ip_all to 2019-01-07T02:47:54.391-0800 I CONTROL [initandlisten] ** bind to all interfaces. If this behavior is desired, start the 2019-01-07T02:47:54.391-0800 I CONTROL [initandlisten] ** server with --bind_ip 127.0.0.1 to disable this warning. 2019-01-07T02:47:54.391-0800 I CONTROL [initandlisten] 2019-01-07T02:47:54.752-0800 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory 'C:/data/db/diagnostic.data' 2019-01-07T02:47:54.755-0800 I NETWORK [initandlisten] waiting for connections on port 27017 2019-01-07T02:48:17.940-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49340 #1 (1 connection now open) 2019-01-07T02:48:17.941-0800 I NETWORK [conn1] received client metadata from 127.0.0.1:49340 conn1: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Cli ent", version: "4.0.5" }, os: { type: "Windows", name: "Microsoft Windows 8.1", architecture: "x86_64", version: "6.3 (build 9600)" } } 2019-01-07T02:49:56.796-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49351 #2 (2 connections now open) 2019-01-07T02:49:56.933-0800 I NETWORK [conn2] end connection 127.0.0.1:49351 (1 connection now open) 2019-01-07T02:49:56.962-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49352 #3 (2 connections now open) 2019-01-07T02:49:57.206-0800 I NETWORK [conn3] end connection 127.0.0.1:49352 (1 connection now open) 2019-01-07T02:50:30.061-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49353 #4 (2 connections now open) 2019-01-07T02:50:30.090-0800 I NETWORK [conn4] end connection 127.0.0.1:49353 (1 connection now open) 2019-01-07T02:50:30.093-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49354 #5 (2 connections now open) 2019-01-07T02:50:30.781-0800 I NETWORK [conn5] end connection 127.0.0.1:49354 (1 connection now open) 2019-01-07T02:51:14.047-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49363 #6 (2 connections now open) 2019-01-07T02:51:14.075-0800 I NETWORK [conn6] end connection 127.0.0.1:49363 (1 connection now open) 2019-01-07T02:51:14.078-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49364 #7 (2 connections now open) 2019-01-07T02:51:14.631-0800 I NETWORK [conn7] end connection 127.0.0.1:49364 (1 connection now open) 2019-01-07T02:51:45.018-0800 W FTDC [ftdc] Uncaught exception in 'FileRenameFailed: The process cannot access the file because it is being used by another process' in full-time diagnostic data capture subsystem. Shutting down the full-time diagnostic data capture subsystem. 2019-01-07T02:56:56.594-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49425 #8 (2 connections now open) 2019-01-07T02:56:56.625-0800 I NETWORK [conn8] end connection 127.0.0.1:49425 (1 connection now open) 2019-01-07T02:56:56.637-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49426 #9 (2 connections now open) 2019-01-07T02:56:56.681-0800 I NETWORK [conn9] end connection 127.0.0.1:49426 (1 connection now open) 2019-01-07T02:57:30.598-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49432 #10 (2 connections now open) 2019-01-07T02:57:30.626-0800 I NETWORK [conn10] end connection 127.0.0.1:49432 (1 connection now open) 2019-01-07T02:57:30.628-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49433 #11 (2 connections now open) 2019-01-07T02:57:31.459-0800 I NETWORK [conn11] end connection 127.0.0.1:49433 (1 connection now open) 2019-01-07T03:18:38.941-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49562 #12 (2 connections now open) 2019-01-07T03:18:38.976-0800 I NETWORK [conn12] received client metadata from 127.0.0.1:49562 conn12: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:18:39.032-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49563 #13 (3 connections now open) 2019-01-07T03:18:39.033-0800 I NETWORK [conn13] received client metadata from 127.0.0.1:49563 conn13: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:18:40.117-0800 I NETWORK [conn13] end connection 127.0.0.1:49563 (2 connections now open) 2019-01-07T03:18:40.118-0800 I NETWORK [conn12] end connection 127.0.0.1:49562 (1 connection now open) 2019-01-07T03:19:27.082-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49568 #14 (2 connections now open) 2019-01-07T03:19:27.120-0800 I NETWORK [conn14] received client metadata from 127.0.0.1:49568 conn14: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:19:27.196-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49569 #15 (3 connections now open) 2019-01-07T03:19:27.206-0800 I NETWORK [conn15] received client metadata from 127.0.0.1:49569 conn15: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:19:28.714-0800 I NETWORK [conn15] end connection 127.0.0.1:49569 (2 connections now open) 2019-01-07T03:19:28.715-0800 I NETWORK [conn14] end connection 127.0.0.1:49568 (1 connection now open) 2019-01-07T03:20:39.865-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49573 #16 (2 connections now open) 2019-01-07T03:20:39.881-0800 I NETWORK [conn16] received client metadata from 127.0.0.1:49573 conn16: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:20:39.930-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49574 #17 (3 connections now open) 2019-01-07T03:20:39.930-0800 I NETWORK [conn17] received client metadata from 127.0.0.1:49574 conn17: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:20:41.511-0800 I NETWORK [conn17] end connection 127.0.0.1:49574 (2 connections now open) 2019-01-07T03:20:41.512-0800 I NETWORK [conn16] end connection 127.0.0.1:49573 (1 connection now open) 2019-01-07T03:21:33.355-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49575 #18 (2 connections now open) 2019-01-07T03:21:33.368-0800 I NETWORK [conn18] received client metadata from 127.0.0.1:49575 conn18: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:21:33.416-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49576 #19 (3 connections now open) 2019-01-07T03:21:33.417-0800 I NETWORK [conn19] received client metadata from 127.0.0.1:49576 conn19: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:21:33.553-0800 I NETWORK [conn19] end connection 127.0.0.1:49576 (2 connections now open) 2019-01-07T03:21:33.554-0800 I NETWORK [conn18] end connection 127.0.0.1:49575 (1 connection now open) 2019-01-07T03:25:04.625-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49598 #20 (2 connections now open) 2019-01-07T03:25:04.639-0800 I NETWORK [conn20] received client metadata from 127.0.0.1:49598 conn20: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:25:04.689-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49599 #21 (3 connections now open) 2019-01-07T03:25:04.690-0800 I NETWORK [conn21] received client metadata from 127.0.0.1:49599 conn21: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:25:04.765-0800 I NETWORK [conn21] end connection 127.0.0.1:49599 (2 connections now open) 2019-01-07T03:25:04.766-0800 I NETWORK [conn20] end connection 127.0.0.1:49598 (1 connection now open) 2019-01-07T03:32:45.697-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49702 #22 (2 connections now open) 2019-01-07T03:32:45.711-0800 I NETWORK [conn22] received client metadata from 127.0.0.1:49702 conn22: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:32:45.761-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49703 #23 (3 connections now open) 2019-01-07T03:32:45.762-0800 I NETWORK [conn23] received client metadata from 127.0.0.1:49703 conn23: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:32:45.827-0800 I NETWORK [conn23] end connection 127.0.0.1:49703 (2 connections now open) 2019-01-07T03:32:45.829-0800 I NETWORK [conn22] end connection 127.0.0.1:49702 (1 connection now open) 2019-01-07T03:33:30.294-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49705 #24 (2 connections now open) 2019-01-07T03:33:30.309-0800 I NETWORK [conn24] received client metadata from 127.0.0.1:49705 conn24: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:33:30.401-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49706 #25 (3 connections now open) 2019-01-07T03:33:30.411-0800 I NETWORK [conn25] received client metadata from 127.0.0.1:49706 conn25: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:33:30.487-0800 I NETWORK [conn25] end connection 127.0.0.1:49706 (2 connections now open) 2019-01-07T03:33:30.505-0800 I NETWORK [conn24] end connection 127.0.0.1:49705 (1 connection now open) 2019-01-07T03:34:10.249-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49708 #26 (2 connections now open) 2019-01-07T03:34:10.290-0800 I NETWORK [conn26] received client metadata from 127.0.0.1:49708 conn26: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:34:10.348-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49709 #27 (3 connections now open) 2019-01-07T03:34:10.350-0800 I NETWORK [conn27] received client metadata from 127.0.0.1:49709 conn27: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:34:10.468-0800 I NETWORK [conn27] end connection 127.0.0.1:49709 (2 connections now open) 2019-01-07T03:34:10.470-0800 I NETWORK [conn26] end connection 127.0.0.1:49708 (1 connection now open) 2019-01-07T03:34:40.345-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49711 #28 (2 connections now open) 2019-01-07T03:34:40.378-0800 I NETWORK [conn28] received client metadata from 127.0.0.1:49711 conn28: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:34:40.433-0800 I NETWORK [listener] connection accepted from 127.0.0.1:49712 #29 (3 connections now open) 2019-01-07T03:34:40.436-0800 I NETWORK [conn29] received client metadata from 127.0.0.1:49712 conn29: { driver: { name: "mongo-java-driver", version: "3.6.3" }, os: { type: "Windo ws", name: "Windows 8.1", architecture: "amd64", version: "6.3" }, platform: "Java/Oracle Corporation/1.8.0_192-b12" } 2019-01-07T03:34:42.807-0800 I NETWORK [conn28] end connection 127.0.0.1:49711 (2 connections now open) 2019-01-07T03:34:42.847-0800 I NETWORK [conn29] end connection 127.0.0.1:49712 (1 connection now open) |
|
Here is the mongodb shell path and output i got C:>cd C:\Program Files\MongoDB\Server\4.0\bin C:\Program Files\MongoDB\Server\4.0\bin>mongo
|
|
What about from the ycsb load? |
|
you mean starting the server from ycsb or the path use |
|
When you ran the 'ycsb load ...' there should have need some error output to the terminal. The code prints a message and/or stack trace when there is an insert failure. |
|
yes there is, and this is the information that is printed C:\YCSB-14\ycsb-0.14.0>C:\Python27\python.exe bin/ycsb load mongodb-async -s -P workloads/workloada > outputworkLoadALoad.txt Loading workload... C:\YCSB-14\ycsb-0.14.0> |
|
You are getting a duplicate key exception. That means that the collection has some other data in it. You should be able to clean it up by connection via the MongoDB shell and then running the following commands (in the MongoDB Shell): Try running the load again once the remove completes. |
|
Thanks it work, you are a saving grace, I appreciate so much. |
|
No problem. I'm glad we finally figure it out. |
I use the following command to load data in mongodb , but the following raed and update fail keep popping up. pls how do i avoid this problem
bin/ycsb load mongodb-async -s -P workloads/workloada > outputLoad.txt
mongo client connection created with mongodb://localhost:27017/ycsb?w=1
[OVERALL] | RunTime(ms) | 3632
[OVERALL] | Throughput(ops/sec) | 275.3303965
[TOTAL_GCS_PS_Scavenge] | Count | 3
[TOTAL_GC_TIME_PS_Scavenge] | Time(ms) | 23
[TOTAL_GC_TIME_%PS_Scavenge] | Time(%) | 0.633259912
[TOTAL_GCS_PS_MarkSweep] | Count | 0
[TOTAL_GC_TIME_PS_MarkSweep] | Time(ms) | 0
[TOTAL_GC_TIME%PS_MarkSweep] | Time(%) | 0
[TOTAL_GCs] | Count | 3
[TOTAL_GC_TIME] | Time(ms) | 23
[TOTAL_GC_TIME%] | Time(%) | 0.633259912
[READ] | Operations | 102
[READ] | AverageLatency(us) | 3149.284314
[READ] | MinLatency(us) | 861
[READ] | MaxLatency(us) | 105855
[READ] | 95thPercentileLatency(us) | 8383
[READ] | 99thPercentileLatency(us) | 26991
[READ] | Return=OK | 102
[READ] | Return=NOT_FOUND | 840
[UPDATE-FAILED] | Operations | 55
[UPDATE-FAILED] | AverageLatency(us) | 3327.836364
[UPDATE-FAILED] | MinLatency(us) | 1126
[UPDATE-FAILED] | MaxLatency(us) | 25327
[UPDATE-FAILED] | 95thPercentileLatency(us) | 6971
[UPDATE-FAILED] | 99thPercentileLatency(us) | 24703
[CLEANUP] | Operations | 1
[CLEANUP] | AverageLatency(us) | 3355
[CLEANUP] | MinLatency(us) | 3354
[CLEANUP] | MaxLatency(us) | 3355
[CLEANUP] | 95thPercentileLatency(us) | 3355
[CLEANUP] | 99thPercentileLatency(us) | 3355
[READ-FAILED] | Operations | 840
[READ-FAILED] | AverageLatency(us) | 1995.982143
[READ-FAILED] | MinLatency(us) | 540
[READ-FAILED] | MaxLatency(us) | 202239
[READ-FAILED] | 95thPercentileLatency(us) | 4691
[READ-FAILED] | 99thPercentileLatency(us) | 18239
[UPDATE] | Operations | 3
[UPDATE] | AverageLatency(us) | 1630
[UPDATE] | MinLatency(us) | 1185
[UPDATE] | MaxLatency(us) | 2311
[UPDATE] | 95thPercentileLatency(us) | 2311
[UPDATE] | 99thPercentileLatency(us) | 2311
[UPDATE] | Return=OK | 3
[UPDATE] | Return=NOT_FOUND | 55
The text was updated successfully, but these errors were encountered: