Bug 1051446 - [origin_cartridge_101]Gear-up will be triggered twice continuously when apache benchmark to send multiple requests to haproxy
Summary: [origin_cartridge_101]Gear-up will be triggered twice continuously when apach...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OpenShift Online
Classification: Red Hat
Component: Image
Version: 2.x
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ---
: ---
Assignee: Dan McPherson
QA Contact: libra bugs
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-01-10 10:00 UTC by Lei Zhang
Modified: 2015-05-15 00:36 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-01-30 00:55:13 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Lei Zhang 2014-01-10 10:00:46 UTC
Description of problem:
Give one scalable app created(e.g.,mypython26s), use command 'ab' to send multiple request to haproxy with 20 sessions from instance, found gear-up will be triggered twice.


--------------Check haproxy/logs/scale_events.log-----------------------
D, [2014-01-10T02:13:20.941812 #21672] DEBUG -- : Local sessions 13
D, [2014-01-10T02:13:20.941980 #21672] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-10T02:13:20.945680 #21672] DEBUG -- : Local sessions 15
D, [2014-01-10T02:13:20.945762 #21672] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-10T02:13:20.945876 #21672] DEBUG -- : GEAR_INFO - capacity: 93.75% gear_count: 1 sessions: 15 up/remove_thresh: 90.0%/1.0% sec_left_til_remove: 530 gear_remove_thresh: 0/20
D, [2014-01-10T02:13:26.003736 #21672] DEBUG -- : Local sessions 16
D, [2014-01-10T02:13:26.003883 #21672] DEBUG -- : Got stats from 0 remote proxies.
I, [2014-01-10T02:13:26.004014 #21672]  INFO -- : GEAR_UP - capacity: 100.0% gear_count: 1 sessions: 16 up_thresh: 90.0%
I, [2014-01-10T02:14:52.276431 #23662]  INFO -- : Starting haproxy_ctld
I, [2014-01-10T02:14:57.349468 #23662]  INFO -- : GEAR_UP - capacity: 100.0% gear_count: 1 sessions: 16 up_thresh: 90.0%
D, [2014-01-10T02:15:40.503400 #24393] DEBUG -- : Local sessions 0
D, [2014-01-10T02:15:40.508440 #24393] DEBUG -- : Got stats from 0 remote proxies.
I, [2014-01-10T02:15:40.508666 #24393]  INFO -- : Starting haproxy_ctld
D, [2014-01-10T02:15:40.510103 #24393] DEBUG -- : Local sessions 0
D, [2014-01-10T02:15:40.517605 #24393] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-10T02:15:40.517849 #24393] DEBUG -- : GEAR_INFO - capacity: 0.0% gear_count: 1 sessions: 0 up/remove_thresh: 90.0%/1.0% sec_left_til_remove: 600 gear_remove_thresh: 0/20

Version-Release number of selected component (if applicable):
devenv_4205 

How reproducible:
always

Steps to Reproduce:
1.Create one scalable app
#rhc app create mypython26s python-2.6 -s 
2.use 'ab' to send multiple request to haproxy from instance.
#ab -n 2000000 -c 20 http://mypython26s-chunchen.dev.rhcloud.com/
3.

Actual results:
Gear-up has been triggered twice continuously when ab send multiple request more than session threshold 

Expected results:
Gear-up should just trigger once when ab send multiple request more than session threshold

Additional info:

Comment 1 Meng Bo 2014-01-10 10:41:34 UTC
Not only scale-up, the GEAR_UP event will come by following a GEAR_DOWN as well.

D, [2014-01-10T05:13:15.277575 #21181] DEBUG -- : Local sessions 18
D, [2014-01-10T05:13:15.277823 #21181] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-10T05:13:15.278942 #21181] DEBUG -- : Local sessions 18
D, [2014-01-10T05:13:15.279085 #21181] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-10T05:13:15.279252 #21181] DEBUG -- : GEAR_INFO - capacity: 37.5% gear_count: 3 sessions: 18 up/remove_thresh: 90.0%/55.5% sec_left_til_remove: 0 gear_remove_thresh: 19/20
D, [2014-01-10T05:13:20.300121 #21181] DEBUG -- : Local sessions 21
D, [2014-01-10T05:13:20.300304 #21181] DEBUG -- : Got stats from 0 remote proxies.
I, [2014-01-10T05:13:20.300820 #21181]  INFO -- : GEAR_DOWN - capacity: 43.75% gear_count: 3 sessions: 21 remove_thresh: 55.5%
I, [2014-01-10T05:13:51.050617 #22774]  INFO -- : Starting haproxy_ctld
I, [2014-01-10T05:13:51.065531 #22774]  INFO -- : GEAR_UP - capacity: 93.75% gear_count: 3 sessions: 45 up_thresh: 90.0%
D, [2014-01-10T05:14:36.044367 #23500] DEBUG -- : Local sessions 45
D, [2014-01-10T05:14:36.051699 #23500] DEBUG -- : Got stats from 0 remote proxies.
I, [2014-01-10T05:14:36.051838 #23500]  INFO -- : Starting haproxy_ctld
D, [2014-01-10T05:14:36.056327 #23500] DEBUG -- : Local sessions 45
D, [2014-01-10T05:14:36.056481 #23500] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-10T05:14:36.056884 #23500] DEBUG -- : GEAR_INFO - capacity: 140.625% gear_count: 2 sessions: 45 up/remove_thresh: 90.0%/40.5% sec_left_til_remove: 60 gear_remove_thresh: 0/20

Comment 2 Dan McPherson 2014-01-10 15:29:10 UTC
The issue here is all the 

Starting haproxy_ctld

lines.  There should only be 1 of those.  I am digging into why so many are being started.

Comment 3 Dan McPherson 2014-01-13 01:54:56 UTC
https://github.com/openshift/origin-server/pull/4457

Comment 5 Lei Zhang 2014-01-13 11:53:06 UTC
Verified on devenv_4214



, [2014-01-13T05:58:21.605784 #8432] DEBUG -- : Local sessions 15
D, [2014-01-13T05:58:21.605887 #8432] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-13T05:58:21.605991 #8432] DEBUG -- : GEAR_INFO - capacity: 93.75% gear_count: 1 sessions: 15 up/remove_thresh: 90.0%/1.0% sec_left_til_remove: 570 gear_remove_thresh: 0/20
D, [2014-01-13T05:58:26.608377 #8432] DEBUG -- : Local sessions 17
D, [2014-01-13T05:58:26.608509 #8432] DEBUG -- : Got stats from 0 remote proxies.
I, [2014-01-13T05:58:26.608633 #8432]  INFO -- : add-gear - capacity: 106.25% gear_count: 1 sessions: 17 up_thresh: 90.0%
I, [2014-01-13T06:00:11.914086 #8432]  INFO -- : add-gear - exit_code: 0  output: 
D, [2014-01-13T06:00:11.920485 #8432] DEBUG -- : Local sessions 18
D, [2014-01-13T06:00:11.920595 #8432] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-13T06:00:11.920728 #8432] DEBUG -- : GEAR_INFO - capacity: 56.25% gear_count: 2 sessions: 18 up/remove_thresh: 90.0%/40.5% sec_left_til_remove: 495 gear_remove_thresh: 0/20
D, [2014-01-13T06:00:11.922332 #8432] DEBUG -- : Local sessions 18
D, [2014-01-13T06:00:11.922417 #8432] DEBUG -- : Got stats from 0 remote proxies.
D, [2014-01-13T06:00:11.922512 #8432] DEBUG -- : GEAR_INFO - capacity: 56.25% gear_count: 2 sessions: 18 up/remove_thresh: 90.0%/40.5% sec_left_til_remove: 495 gear_remove_thresh: 0/20
D, [2014-01-13T06:00:16.933261 #8432] DEBUG -- : Local sessions 18
D, [2014-01-13T06:00:16.933465 #8432] DEBUG -- : Got stats from 0 remote proxies.


Note You need to log in before you can comment on or make changes to this bug.