cloud backend: "excessive reactor delay" warning in foolscap log during crawler run

[davidsarah]

04:12:29.018 L20 []#1001 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffn%2F>
04:12:31.475 L20 []#1002 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffn%2F>
04:12:31.476 L20 []#1003 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffo%2F>
04:12:32.140 L20 []#1004 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffo%2F>
04:12:32.141 L20 []#1005 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffp%2F>
04:12:33.387 L10 []#1006 get_stats() -> {'stats': {'storage_server.accepting_immutable_shares': 1, 'load_monitor.max_load': 1.1067259311676025, 'load_monitor.avg_load': 0.042395317554473878, 'node.uptime': 327.79333305358887, 'cpu_monitor.1min_avg': 0.00066662406928675157, 'cpu_monitor.total': 9.1099999999999994, 'storage_server.allocated': 0, 'storage_server.total_bucket_count': 2, 'cpu_monitor.5min_avg': 0.0032332485251684402}, 'counters': {}}
04:12:35.599 L20 []#1007 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffp%2F>
04:12:35.600 L20 []#1008 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffq%2F>
04:12:37.038 L23 []#1009 excessive reactor delay ({'incarnation': ('\x93G\x9ac\x98\xac`\xc7', None), 'level': 23, 'format': 'excessive reactor delay (%ss)', 'args': (1.160836935043335,), 'num': 1009, 'time': 1354680757.0389249}s)

04:12:37.048 L20 []#1010 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffq%2F>
04:12:37.048 L20 []#1011 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffr%2F>
04:12:38.564 L20 []#1012 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffr%2F>
04:12:38.565 L20 []#1013 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffs%2F>
04:12:40.639 L23 []#1014 excessive reactor delay ({'incarnation': ('\x93G\x9ac\x98\xac`\xc7', None), 'level': 23, 'format': 'excessive reactor delay (%ss)', 'args': (1.1003279685974121,), 'num': 1014, 'time': 1354680760.639235}s)
04:12:40.640 L20 []#1015 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffs%2F>
04:12:40.648 L20 []#1016 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Fft%2F>
04:12:41.921 L20 []#1017 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Fft%2F>
04:12:41.922 L20 []#1018 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffu%2F>
04:12:43.097 L20 []#1019 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffu%2F>
04:12:43.098 L20 []#1020 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffv%2F>
04:12:45.710 L20 []#1021 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffv%2F>
04:12:45.711 L20 []#1022 Starting factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffw%2F>
04:12:47.089 L20 []#1023 Stopping factory <HTTPClientFactory: http://lae-f7eace39-bph5vpnzvzbt7bifap7pbevyodpsmyy7.s3.amazonaws.com/?prefix=shares%2Ffw%2F>

I think this was a bucket counter run. It was on an LAE storage server (a t1.micro EC2 instance), so it is possible that the instance was using too much CPU and was throttled, but I'm not sure of that.

[davidsarah]

If I'm reading the log correctly, the delays were for 1.16 and 1.10 seconds.