evansolomon / nodejs-kinesis-client-library

Node.js implementation of Amazon's Kinesis Client Library.
51 stars 16 forks source link

Multiple Kinesis Shards #5

Closed basdag closed 9 years ago

basdag commented 9 years ago

Hi again @evansolomon, running test like I mentioned, I found that when the shards in Kinesis are more than one - in my case 4 - an ConditionalCheckFailedException exception start rising constantly:

info: k/lib/sequential_executor.js:77:10)\n    at Request.emit (/src/node_modules/aws-sdk/lib/request.js:604:14)\n    at Request.transition (/src/node_modules/aws-sdk/lib/request.js:21:12)\n    at AcceptorStateMachine.runTo (/src/node_modules/aws-sdk/lib/state_machine.js:14:12)\n    at /src/node_modules/aws-sdk/lib/state_machine.js:26:10\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:22:9)\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:606:12)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:104:18)","code":"ConditionalCheckFailedException"},"msg":"The conditional request failed","time":"2015-02-12T21:47:09.632Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000000","hostname":"xxxx","pid":785,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:09.672Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:09.672Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"shardId":"shardId-000000000000","exitCode":1,"msg":"Consumer exited","time":"2015-02-12T21:47:09.814Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","leaseCounter":1129,"msg":"Found available shard","time":"2015-02-12T21:47:10.185Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","leaseCounter":1129,"msg":"Spawning consumer","time":"2015-02-12T21:47:10.186Z","v":0}
info: Logging output: /zoinks.consumer.log source=zoinks.consumer, type=GenericInfo, timestamp=2015-02-12T21:47:13.816Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","leaseCounter":1129,"msg":"Found available shard","time":"2015-02-12T21:47:15.264Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","leaseCounter":1129,"msg":"Spawning consumer","time":"2015-02-12T21:47:15.264Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":791,"level":30,"leaseCounter":1129,"tableName":"xxxx-kinesis-table","msg":"Setting up lease","time":"2015-02-12T21:47:15.268Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":745,"level":50,"err":{"message":"The conditional request failed","name":"ConditionalCheckFailedException","stack":"ConditionalCheckFailedException: The conditional request failed\n    at Request.extractError (/src/node_modules/aws-sdk/lib/protocol/json.js:43:27)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:100:18)\n    at Request.emit (/src/node_modules/aws-sdk/lib/sequential_executor.js:77:10)\n    at Request.emit (/src/node_modules/aws-sdk/lib/request.js:604:14)\n    at Request.transition (/src/node_modules/aws-sdk/lib/request.js:21:12)\n    at AcceptorStateMachine.runTo (/src/node_modules/aws-sdk/lib/state_machine.js:14:12)\n    at /src/node_modules/aws-sdk/lib/state_machine.js:26:10\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:22:9)\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:606:12)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:104:18)","code":"ConditionalCheckFailedException"},"msg":"The conditional request failed","time":"2015-02-12T21:47:16.391Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":745,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:16.400Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:16.403Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"shardId":"shardId-000000000001","exitCode":1,"msg":"Consumer exited","time":"2015-02-12T21:47:16.475Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":791,"level":30,"checkpoint":"49547685893943373220510730214528430926853208241659183122","msg":"Got starting checkpoint","time":"2015-02-12T21:47:16.663Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":791,"level":30,"iteratorType":"AFTER_SEQUENCE_NUMBER","sequenceNumber":"49547685893943373220510730214528430926853208241659183122","msg":"Updating shard iterator","time":"2015-02-12T21:47:16.665Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":791,"level":30,"ShardIterator":"AAAAAAAAAAF6B3FFIDsDc3YvBfDOt4NiJNGc6ipDmQl9RYfuJylOWS+2YTy+tQPMcud+Z705+ufkimCcyzN2Zxen5BM0SCoGNWFj9MUVZMbFnRBNVT0NPhKIlYcjt/JM06wpiJD+/j3KHC80TRE3A6EvPuqo5bEV4oENzJsUuCDrUFTDc//jRe9ea04AqAIdQ9HSXp7Yc9M=","msg":"Updated shard iterator","time":"2015-02-12T21:47:16.846Z","v":0}
info: Kinesis Reader source=zoinks.consumer, type=Uploader has been initialized, timestamp=2015-02-12T21:47:16.926Z, 
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":791,"level":30,"msg":"Starting getRecords loop","time":"2015-02-12T21:47:16.954Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":791,"level":30,"msg":"Starting reserveLease loop","time":"2015-02-12T21:47:17.040Z","v":0}
info: Logging output: /zoinks.consumer.log source=zoinks.consumer, type=GenericInfo, timestamp=2015-02-12T21:47:17.522Z, 
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000000","hostname":"xxxx","pid":739,"level":50,"err":{"message":"The conditional request failed","name":"ConditionalCheckFailedException","stack":"ConditionalCheckFailedException: The conditional request failed\n    at Request.extractError (/src/node_modules/aws-sdk/lib/protocol/json.js:43:27)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:100:18)\n    at Request.emit (/src/node_modules/aws-sdk/lib/sequential_executor.js:77:10)\n    at Request.emit (/src/node_modules/aws-sdk/lib/request.js:604:14)\n    at Request.transition (/src/node_modules/aws-sdk/lib/request.js:21:12)\n    at AcceptorStateMachine.runTo (/src/node_modules/aws-sdk/lib/state_machine.js:14:12)\n    at /src/node_modules/aws-sdk/lib/state_machine.js:26:10\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:22:9)\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:606:12)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:104:18)","code":"ConditionalCheckFailedException"},"msg":"The conditional request failed","time":"2015-02-12T21:47:17.643Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000000","hostname":"xxxx","pid":739,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:17.645Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:17.646Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"shardId":"shardId-000000000000","exitCode":1,"msg":"Consumer exited","time":"2015-02-12T21:47:17.721Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000003","hostname":"xxxx","pid":631,"level":50,"err":{"message":"Shard shardId-000000000003 in stream xxxx under account 164015737599 does not exist","name":"ResourceNotFoundException","stack":"ResourceNotFoundException: Shard shardId-000000000003 in stream xxxx under account 164015737599 does not exist\n    at Request.extractError (/src/node_modules/aws-sdk/lib/protocol/json.js:43:27)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:100:18)\n    at Request.emit (/src/node_modules/aws-sdk/lib/sequential_executor.js:77:10)\n    at Request.emit (/src/node_modules/aws-sdk/lib/request.js:604:14)\n    at Request.transition (/src/node_modules/aws-sdk/lib/request.js:21:12)\n    at AcceptorStateMachine.runTo (/src/node_modules/aws-sdk/lib/state_machine.js:14:12)\n    at /src/node_modules/aws-sdk/lib/state_machine.js:26:10\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:22:9)\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:606:12)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:104:18)","code":"ResourceNotFoundException"},"msg":"Shard shardId-000000000003 in stream xxxx under account 164015737599 does not exist","time":"2015-02-12T21:47:17.803Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000003","hostname":"xxxx","pid":631,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:17.826Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:17.838Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"shardId":"shardId-000000000003","exitCode":1,"msg":"Consumer exited","time":"2015-02-12T21:47:17.920Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":801,"level":30,"leaseCounter":1129,"tableName":"xxxx-kinesis-table","msg":"Setting up lease","time":"2015-02-12T21:47:17.920Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":801,"level":50,"err":{"message":"The conditional request failed","name":"ConditionalCheckFailedException","stack":"ConditionalCheckFailedException: The conditional request failed\n    at Request.extractError (/src/node_modules/aws-sdk/lib/protocol/json.js:43:27)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:100:18)\n    at Request.emit (/src/node_modules/aws-sdk/lib/sequential_executor.js:77:10)\n    at Request.emit (/src/node_modules/aws-sdk/lib/request.js:604:14)\n    at Request.transition (/src/node_modules/aws-sdk/lib/request.js:21:12)\n    at AcceptorStateMachine.runTo (/src/node_modules/aws-sdk/lib/state_machine.js:14:12)\n    at /src/node_modules/aws-sdk/lib/state_machine.js:26:10\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:22:9)\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:606:12)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:104:18)","code":"ConditionalCheckFailedException"},"msg":"The conditional request failed","time":"2015-02-12T21:47:19.394Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":801,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:19.402Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:19.415Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"shardId":"shardId-000000000001","exitCode":1,"msg":"Consumer exited","time":"2015-02-12T21:47:19.471Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"msg":"Error fetching available shards","time":"2015-02-12T21:47:20.346Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"err":{"message":"Stream xxxx under account 164015737599 not found.","name":"ResourceNotFoundException","stack":"ResourceNotFoundException: Stream xxxx under account 164015737599 not found.\n    at Request.extractError (/src/node_modules/aws-sdk/lib/protocol/json.js:43:27)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:100:18)\n    at Request.emit (/src/node_modules/aws-sdk/lib/sequential_executor.js:77:10)\n    at Request.emit (/src/node_modules/aws-sdk/lib/request.js:604:14)\n    at Request.transition (/src/node_modules/aws-sdk/lib/request.js:21:12)\n    at AcceptorStateMachine.runTo (/src/node_modules/aws-sdk/lib/state_machine.js:14:12)\n    at /src/node_modules/aws-sdk/lib/state_machine.js:26:10\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:22:9)\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:606:12)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:104:18)","code":"ResourceNotFoundException"},"msg":"Stream xxxx under account 164015737599 not found.","time":"2015-02-12T21:47:20.396Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"msg":"Killing all consumers","time":"2015-02-12T21:47:20.397Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"id":87,"msg":"Killing consumer","time":"2015-02-12T21:47:20.397Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"id":124,"msg":"Killing consumer","time":"2015-02-12T21:47:20.429Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"id":126,"msg":"Killing consumer","time":"2015-02-12T21:47:20.446Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"id":129,"msg":"Killing consumer","time":"2015-02-12T21:47:20.446Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"id":131,"msg":"Killing consumer","time":"2015-02-12T21:47:20.446Z","v":0}
info: Logging output: /zoinks.consumer.log source=zoinks.consumer, type=GenericInfo, timestamp=2015-02-12T21:47:21.737Z, 
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":807,"level":30,"leaseCounter":1129,"tableName":"xxxx-kinesis-table","msg":"Setting up lease","time":"2015-02-12T21:47:22.006Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":807,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:22.046Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:22.047Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","exitCode":0,"msg":"Consumer exited","time":"2015-02-12T21:47:22.056Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"msg":"Error fetching available shards","time":"2015-02-12T21:47:25.474Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":50,"err":{"message":"Stream xxxx under account 164015737599 not found.","name":"ResourceNotFoundException","stack":"ResourceNotFoundException: Stream xxxx under account 164015737599 not found.\n    at Request.extractError (/src/node_modules/aws-sdk/lib/protocol/json.js:43:27)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:100:18)\n    at Request.emit (/src/node_modules/aws-sdk/lib/sequential_executor.js:77:10)\n    at Request.emit (/src/node_modules/aws-sdk/lib/request.js:604:14)\n    at Request.transition (/src/node_modules/aws-sdk/lib/request.js:21:12)\n    at AcceptorStateMachine.runTo (/src/node_modules/aws-sdk/lib/state_machine.js:14:12)\n    at /src/node_modules/aws-sdk/lib/state_machine.js:26:10\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:22:9)\n    at Request.<anonymous> (/src/node_modules/aws-sdk/lib/request.js:606:12)\n    at Request.callListeners (/src/node_modules/aws-sdk/lib/sequential_executor.js:104:18)","code":"ResourceNotFoundException"},"msg":"Stream xxxx under account 164015737599 not found.","time":"2015-02-12T21:47:25.480Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":791,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:25.616Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:25.618Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","exitCode":0,"msg":"Consumer exited","time":"2015-02-12T21:47:25.633Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000002","hostname":"xxxx","pid":761,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:28.165Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:28.172Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000002","exitCode":0,"msg":"Consumer exited","time":"2015-02-12T21:47:28.209Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","leaseCounter":1130,"msg":"Found available shard","time":"2015-02-12T21:47:30.423Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000000","hostname":"xxxx","pid":773,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:34.917Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:34.919Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","exitCode":0,"msg":"Consumer exited","time":"2015-02-12T21:47:34.933Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:47:35.593Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:47:40.588Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:47:45.767Z","v":0}
{"name":"KinesisConsumer","streamName":"xxxx","shardId":"shardId-000000000001","hostname":"xxxx","pid":547,"level":30,"msg":"Starting shutdown","time":"2015-02-12T21:47:49.185Z","v":0}
warn: Kinesis Reader source=zoinks.consumer, type=Kinesis Consumer exited, timestamp=2015-02-12T21:47:49.188Z, 
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000001","exitCode":0,"msg":"Consumer exited","time":"2015-02-12T21:47:49.207Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:47:50.686Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:47:55.774Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:00.846Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:05.810Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:10.973Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:15.903Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:20.966Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:25.997Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:31.046Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:36.289Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:41.239Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:46.327Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:51.355Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:48:56.476Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:01.433Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:06.469Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:11.586Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:16.690Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:21.637Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:26.682Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:31.704Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:37.281Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:41.836Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:46.897Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:51.925Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:49:57.046Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:02.074Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:07.169Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:12.213Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:17.222Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:22.259Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:27.374Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:32.333Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:37.360Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:42.428Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:47.436Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:52.446Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:50:57.510Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:02.510Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:07.548Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:12.682Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:17.614Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:22.638Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:27.712Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:32.745Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:37.787Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:42.814Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:47.863Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:52.912Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:51:57.989Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:03.013Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:08.052Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:13.092Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:18.122Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:23.223Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:28.247Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:33.275Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:38.300Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:43.397Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:48.579Z","v":0}
{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-12T21:52:53.688Z","v":0}

Any idea what can be causing it?

Thanks again for your time and support.

evansolomon commented 9 years ago

On its own it's not necessarily bad to get the ConditionalCheckFailedException error. Usually it just means that multiple workers tried to acquire the same shard at about the same time. The check is in place to make sure that only one of those attempts works.

It seems like at some point that error stops and you start getting "Found available shard" logs. I would expect to see those followed by attempts to spawn a new consumer to process them (you should see a "Spawning consumer" log when that happens).

From a quick look, one possible problem is that isShuttingDownFromError is set here, which would cause the cluster not to try to spawn a consumer. In that case, I'd expect to see the cluster itself exiting soon, which isn't happening.

Can you try checking that?

basdag commented 9 years ago

Yes I was checking the ConsumerCluster it makes total sense, because the cluster will receive the order to be reset in 40 seconds which is what it set to, so that is why Found available shard is show repeatedly. However, the question would be if it is a good behavior for the cluster to reset itself just because the ConditionalCheckFailedException? I think it would be need it to filter the kind of errors to see which ones makes sense to make the cluster reset, what do you think?

evansolomon commented 9 years ago

the question would be if it is a good behavior for the cluster to reset itself just because the ConditionalCheckFailedException

I don't think it will. The lease reservation (where the conditional check comes in) is done in the consumer. So the individual consumer will kill itself but the cluster (which owns the consumer) will keep running. In your logs, all of the "... exited" logs are from consumers exiting, not clusters.

To clarify, this is the terminology that the library uses.

evansolomon commented 9 years ago

@basdag is there anything here that is still a problem?

basdag commented 9 years ago

@evansolomon I tested the code this last couple days and still get indefinitely (more than an hour) the next log without the cluster exiting:

{"name":"KinesisCluster","hostname":"xxxx","pid":20,"level":30,"shardId":"shardId-000000000000","leaseCounter":1059,"msg":"Found available shard","time":"2015-02-17T09:37:07.142Z","v":0}

So as we highlight before, the issue its on the isShuttingDownFromError flag, which block the cluster from spawning new consumers, like we discussed. This means that for some reason the cluster is not exiting when logAndEmitError is called. Moreover and correct if I am wrong, I do not see anywhere where is declare the listener for the this.emit('error', err) that is set inside logAndEmitError. If this is true this can be a reason why the flag isShuttingDownFromError is set but nothing happened after, and it gets inside an infinity loop of Found available shard.

Also analyzing the errors in ConsumerCluster, I found an interesting case here where I was wonder, how it is known or ensure that other consumers do not have correct shardIds either, in order to throw an error that will reset everything?

evansolomon commented 9 years ago

I think the non-exiting problem will be fixed by 593875796a63c92450bff69eaa46087d80257038.

The error highlighted is when the shardId argument to spawn() is false-y (e.g. an empty string). It's impossible to spawn a consumer for a false-y shard ID. I'm not sure I understand your question about other consumers having correct shard ID's, but it does seem like that's a case where those consumers' shutdown methods won't run currently.

evansolomon commented 9 years ago

The missing shard ID case should be handled a little better as of 84ff2d24a7f4f29a8ad2cfcdd29eaf7ef6faa449

basdag commented 9 years ago

Hi @evansolomon I apologize for the delay I will try it with this new logs and come back to you for the feedback. I will close this issue, and if something happen I will create a new one. Thanks for your time.