The pattern seems to be that at first, everything is fine, then more players log in and things get extremely laggy. The number of players doesn't seem unusual. Then, one of the players gets disconnected:
2012-10-28 17:07:37 [INFO] ##REDACTED## lost connection: disconnect.genericReasonBefore he got disconnected, the players all see extreme lag. This lag is detected by the debug profiler. Here is the profile output during the problem:
---- Minecraft Profiler Results ----
// I'm working as hard as I can!
Time span: 32806 ms
Tick span: 10 ticks
// This is approximately 0.30 ticks per second. It should be 20 ticks per second
--- BEGIN PROFILE DUMP ---
[00] levels - 99.19%/99.19%
[01] swim2 - 100.00%/100.00%
[02] tick - 99.90%/99.90%
[03] entities - 99.57%/99.57%
[04] regular - 99.95%/99.95%
[05] tick - 99.41%/99.41%
[06] move - 94.70%/94.70%
[06] unspecified - 2.83%/2.83%
[06] entityBaseTick - 0.69%/0.69%
[06] ai - 0.64%/0.64%
[07] newAi - 92.19%/0.64%
[08] goalSelector - 30.32%/0.20%
[09] unspecified - 70.02%/0.14%
[09] canUse - 13.30%/0.03%
[09] pathfind - 5.94%/0.01%
[09] goalStart - 5.72%/0.01%
[10] ng - 54.68%/0.01%
[11] pathfind - 95.03%/0.01%
[11] unspecified - 4.97%/0.00%
[10] unspecified - 41.68%/0.00%
[10] nf - 2.62%/0.00%
[10] mj - 0.46%/0.00%
[10] mw - 0.24%/0.00%
[10] nj - 0.21%/0.00%
[10] mr - 0.06%/0.00%
[10] nh - 0.03%/0.00%
[09] goalTick - 4.30%/0.01%
[10] unspecified - 77.40%/0.01%
[10] pathfind - 21.18%/0.00%
[10] canSee - 1.42%/0.00%
[09] canContinue - 0.73%/0.00%
[08] unspecified - 23.58%/0.15%
[08] controls - 22.13%/0.14%
[09] unspecified - 44.26%/0.06%
[09] look - 32.48%/0.05%
[09] move - 15.11%/0.02%
[09] jump - 8.15%/0.01%
[08] targetSelector - 14.21%/0.09%
[09] unspecified - 87.43%/0.08%
[09] goalStart - 5.32%/0.00%
[10] unspecified - 98.53%/0.00%
[10] nq - 1.47%/0.00%
[09] goalTick - 4.26%/0.00%
[09] canUse - 2.26%/0.00%
[09] canSee - 0.49%/0.00%
[09] canContinue - 0.24%/0.00%
[10] canSee - 66.15%/0.00%
[10] unspecified - 33.85%/0.00%
[08] navigation - 4.43%/0.03%
[08] checkDespawn - 2.41%/0.02%
[08] sensing - 1.76%/0.01%
[08] mob tick - 1.15%/0.01%
[07] unspecified - 5.39%/0.04%
[07] oldAi - 2.42%/0.02%
[08] unspecified - 57.40%/0.01%
[08] ai - 20.96%/0.00%
[08] stroll - 17.22%/0.00%
[09] pathfind - 88.98%/0.00%
[09] unspecified - 11.02%/0.00%
[08] followpath - 4.42%/0.00%
[06] rest - 0.60%/0.60%
[06] travel - 0.29%/0.29%
[07] move - 44.20%/0.14%
[07] unspecified - 33.92%/0.11%
[07] rest - 21.88%/0.07%
[06] chunkCheck - 0.11%/0.11%
[06] mobBaseTick - 0.08%/0.08%
[06] push - 0.03%/0.03%
[06] headTurn - 0.01%/0.01%
[06] looting - 0.01%/0.01%
[06] jump - 0.01%/0.01%
[06] rangeChecks - 0.00%/0.00%
[06] checkLight - 0.00%/0.00%
[07] checkedPosition < toCheckCount - 66.65%/0.00%
[07] unspecified - 18.70%/0.00%
[07] getBrightness - 14.65%/0.00%
[06] getBrightness - 0.00%/0.00%
[06] checkedPosition < toCheckCount - 0.00%/0.00%
[05] unspecified - 0.56%/0.56%
[05] remove - 0.03%/0.03%
[04] remove - 0.03%/0.03%
[04] tileEntities - 0.02%/0.02%
[05] unspecified - 99.31%/0.02%
[05] move - 0.43%/0.00%
[05] checkLight - 0.18%/0.00%
[06] getBrightness - 50.00%/0.00%
[06] unspecified - 41.67%/0.00%
[06] checkedPosition < toCheckCount - 8.33%/0.00%
[05] rest - 0.09%/0.00%
[04] unspecified - 0.00%/0.00%
[04] pendingTileEntities - 0.00%/0.00%
[04] global - 0.00%/0.00%
[03] tickTiles - 0.27%/0.27%
[04] unspecified - 59.94%/0.18%
[04] tickTiles - 21.00%/0.06%
[04] getChunk - 6.92%/0.02%
[04] iceandsnow - 2.65%/0.01%
[04] tickChunk - 2.26%/0.01%
[05] unspecified - 77.10%/0.01%
[05] recheckGaps - 22.90%/0.00%
[06] unspecified - 57.47%/0.00%
[06] getBrightness - 40.35%/0.00%
[06] checkedPosition < toCheckCount - 2.19%/0.00%
[04] thunder - 1.86%/0.01%
[04] checkLight - 1.86%/0.01%
[04] moodSound - 1.54%/0.00%
[04] buildList - 1.43%/0.00%
[04] playerCheckLight - 0.53%/0.00%
[05] unspecified - 64.53%/0.00%
[05] getBrightness - 33.97%/0.00%
[05] checkedPosition < toCheckCount - 1.50%/0.00%
[03] mobSpawner - 0.09%/0.09%
[03] chunkSource - 0.04%/0.04%
[03] tickPending - 0.02%/0.02%
[04] checkLight - 81.84%/0.02%
[05] checkedPosition < toCheckCount - 56.16%/0.01%
[05] getBrightness - 43.17%/0.01%
[05] unspecified - 0.67%/0.00%
[04] unspecified - 18.16%/0.00%
[03] village - 0.00%/0.00%
[03] unspecified - 0.00%/0.00%
[03] chunkMap - 0.00%/0.00%
[03] checkLight - 0.00%/0.00%
[04] getBrightness - 54.51%/0.00%
[04] unspecified - 45.49%/0.00%
[04] checkedPosition < toCheckCount - 0.00%/0.00%
[02] tracker - 0.10%/0.10%
[02] unspecified - 0.00%/0.00%
[02] pools - 0.00%/0.00%
[01] unspecified - 0.00%/0.00%
[00] connection - 0.81%/0.81%
[01] packetflow - 96.52%/0.88%
[02] unspecified - 70.32%/0.62%
[02] travel - 12.17%/0.11%
[03] move - 42.38%/0.05%
[03] unspecified - 36.40%/0.04%
[03] rest - 21.22%/0.02%
[02] move - 4.14%/0.04%
[02] mobBaseTick - 3.18%/0.03%
[02] entityBaseTick - 2.86%/0.03%
[02] rest - 2.69%/0.02%
[02] ai - 1.79%/0.02%
[03] unspecified - 80.67%/0.01%
[03] oldAi - 19.33%/0.00%
[02] push - 1.78%/0.02%
[02] headTurn - 0.43%/0.00%
[02] jump - 0.21%/0.00%
[02] looting - 0.19%/0.00%
[02] rangeChecks - 0.15%/0.00%
[02] chunkCheck - 0.09%/0.00%
[01] playerTick - 2.37%/0.02%
[02] travel - 45.90%/0.01%
[03] move - 97.31%/0.01%
[03] unspecified - 1.35%/0.00%
[03] rest - 1.34%/0.00%
[02] push - 27.21%/0.01%
[02] unspecified - 25.94%/0.01%
[02] entityBaseTick - 0.43%/0.00%
[02] mobBaseTick - 0.22%/0.00%
[02] headTurn - 0.13%/0.00%
[02] ai - 0.11%/0.00%
[03] unspecified - 71.43%/0.00%
[03] oldAi - 28.57%/0.00%
[02] rangeChecks - 0.03%/0.00%
[02] looting - 0.02%/0.00%
[02] jump - 0.02%/0.00%
[01] unspecified - 1.09%/0.01%
[01] keepAlive - 0.03%/0.00%
[00] tallying - 0.00%/0.00%
[00] players - 0.00%/0.00%
[00] tickables - 0.00%/0.00%
[00] snooper - 0.00%/0.00%
--- END PROFILE DUMP ---And here is the debug profiler after the problem has gone away (when "disconnect.genericReason" is logged):
---- Minecraft Profiler Results ----
// You should add flames to things, it makes them go faster!
Time span: 42520 ms
Tick span: 850 ticks
// This is approximately 19.99 ticks per second. It should be 20 ticks per second
--- BEGIN PROFILE DUMP ---
[00] levels - 96.13%/96.13%
[01] swim2 - 99.97%/96.19%
[02] tick - 98.41%/94.66%
[03] entities - 80.71%/76.40%
[04] regular - 98.19%/75.02%
[05] tick - 95.22%/71.43%
[06] ai - 34.74%/24.82%
[07] newAi - 92.46%/22.95%
[08] goalSelector - 40.15%/9.21%
[09] unspecified - 53.27%/4.91%
[09] pathfind - 22.34%/2.06%
[09] goalTick - 11.74%/1.08%
[10] pathfind - 78.81%/0.85%
[10] unspecified - 20.44%/0.22%
[10] canSee - 0.71%/0.01%
[10] checkLight - 0.05%/0.00%
[11] unspecified - 64.54%/0.00%
[11] getBrightness - 33.72%/0.00%
[11] checkedPosition < toCheckCount - 1.74%/0.00%
[09] canUse - 9.29%/0.86%
[09] goalStart - 2.93%/0.27%
[10] unspecified - 60.07%/0.16%
[10] ng - 34.71%/0.09%
[11] pathfind - 95.32%/0.09%
[11] unspecified - 4.68%/0.00%
[10] nf - 3.96%/0.01%
[10] mj - 0.32%/0.00%
[10] mh - 0.26%/0.00%
[10] mq - 0.20%/0.00%
[10] nj - 0.13%/0.00%
[10] mu - 0.12%/0.00%
[10] mw - 0.09%/0.00%
[10] mr - 0.08%/0.00%
[10] mp - 0.06%/0.00%
[10] nh - 0.00%/0.00%
[09] canContinue - 0.42%/0.04%
[08] unspecified - 24.22%/5.56%
[08] targetSelector - 14.57%/3.34%
[09] unspecified - 88.28%/2.95%
[09] goalStart - 4.51%/0.15%
[10] unspecified - 99.99%/0.15%
[10] nr - 0.01%/0.00%
[09] goalTick - 3.62%/0.12%
[09] canUse - 2.41%/0.08%
[09] canSee - 1.10%/0.04%
[09] canContinue - 0.08%/0.00%
[10] unspecified - 63.84%/0.00%
[10] canSee - 36.16%/0.00%
[08] controls - 14.49%/3.32%
[09] unspecified - 76.36%/2.54%
[09] look - 13.82%/0.46%
[09] move - 6.14%/0.20%
[09] jump - 3.67%/0.12%
[08] checkDespawn - 2.71%/0.62%
[08] sensing - 1.50%/0.34%
[08] navigation - 1.45%/0.33%
[08] mob tick - 0.91%/0.21%
[07] unspecified - 5.50%/1.37%
[07] oldAi - 2.03%/0.50%
[08] unspecified - 70.06%/0.35%
[08] ai - 21.68%/0.11%
[08] stroll - 6.83%/0.03%
[09] pathfind - 93.94%/0.03%
[09] unspecified - 6.06%/0.00%
[08] followpath - 1.43%/0.01%
[06] unspecified - 29.88%/21.34%
[06] travel - 17.70%/12.64%
[07] move - 48.49%/6.13%
[07] unspecified - 30.72%/3.88%
[07] rest - 20.79%/2.63%
[06] entityBaseTick - 8.05%/5.75%
[06] mobBaseTick - 4.17%/2.98%
[06] move - 1.65%/1.18%
[06] push - 1.40%/1.00%
[06] headTurn - 0.68%/0.49%
[06] rest - 0.58%/0.41%
[06] chunkCheck - 0.42%/0.30%
[06] looting - 0.27%/0.19%
[06] rangeChecks - 0.26%/0.18%
[06] jump - 0.21%/0.15%
[06] checkLight - 0.00%/0.00%
[07] checkedPosition < toCheckCount - 38.51%/0.00%
[07] unspecified - 32.82%/0.00%
[07] getBrightness - 28.67%/0.00%
[06] getBrightness - 0.00%/0.00%
[06] checkedPosition < toCheckCount - 0.00%/0.00%
[05] unspecified - 4.43%/3.32%
[05] remove - 0.35%/0.26%
[04] tileEntities - 1.62%/1.24%
[05] unspecified - 95.89%/1.19%
[05] checkLight - 3.99%/0.05%
[06] checkedPosition < toCheckCount - 73.03%/0.04%
[06] getBrightness - 24.50%/0.01%
[06] unspecified - 2.47%/0.00%
[05] move - 0.09%/0.00%
[05] rest - 0.03%/0.00%
[04] remove - 0.15%/0.11%
[04] unspecified - 0.04%/0.03%
[04] pendingTileEntities - 0.00%/0.00%
[04] global - 0.00%/0.00%
[03] tickTiles - 14.39%/13.62%
[04] unspecified - 54.76%/7.46%
[04] tickTiles - 17.63%/2.40%
[05] unspecified - 99.13%/2.38%
[05] checkLight - 0.85%/0.02%
[06] unspecified - 58.19%/0.01%
[06] getBrightness - 26.21%/0.01%
[06] checkedPosition < toCheckCount - 15.60%/0.00%
[05] getBrightness - 0.01%/0.00%
[05] checkedPosition < toCheckCount - 0.01%/0.00%
[04] moodSound - 7.81%/1.06%
[04] getChunk - 6.90%/0.94%
[04] tickChunk - 4.95%/0.67%
[05] recheckGaps - 70.18%/0.47%
[06] unspecified - 71.30%/0.34%
[06] getBrightness - 25.78%/0.12%
[06] checkedPosition < toCheckCount - 2.92%/0.01%
[05] unspecified - 29.82%/0.20%
[04] iceandsnow - 2.55%/0.35%
[04] buildList - 1.86%/0.25%
[04] thunder - 1.69%/0.23%
[04] checkLight - 1.45%/0.20%
[04] playerCheckLight - 0.39%/0.05%
[05] unspecified - 65.56%/0.03%
[05] getBrightness - 32.60%/0.02%
[05] checkedPosition < toCheckCount - 1.85%/0.00%
[03] mobSpawner - 4.16%/3.94%
[03] tickPending - 0.43%/0.41%
[04] checkLight - 67.16%/0.27%
[05] checkedPosition < toCheckCount - 75.51%/0.21%
[05] getBrightness - 23.30%/0.06%
[05] unspecified - 1.19%/0.00%
[04] unspecified - 32.84%/0.13%
[03] village - 0.10%/0.09%
[03] chunkSource - 0.09%/0.09%
[04] unspecified - 99.37%/0.08%
[04] checkLight - 0.63%/0.00%
[05] unspecified - 55.85%/0.00%
[05] getBrightness - 32.58%/0.00%
[05] checkedPosition < toCheckCount - 11.58%/0.00%
[03] unspecified - 0.06%/0.06%
[03] checkLight - 0.04%/0.04%
[04] checkedPosition < toCheckCount - 95.74%/0.04%
[04] unspecified - 2.82%/0.00%
[04] getBrightness - 1.44%/0.00%
[03] chunkMap - 0.02%/0.02%
[02] tracker - 1.55%/1.49%
[02] unspecified - 0.03%/0.03%
[02] pools - 0.00%/0.00%
[02] timeSync - 0.00%/0.00%
[01] unspecified - 0.03%/0.03%
[00] connection - 3.75%/3.75%
[01] packetflow - 93.76%/3.52%
[02] unspecified - 93.67%/3.30%
[02] travel - 2.70%/0.09%
[03] move - 46.72%/0.04%
[03] unspecified - 33.99%/0.03%
[03] rest - 19.29%/0.02%
[02] entityBaseTick - 0.89%/0.03%
[02] move - 0.69%/0.02%
[02] mobBaseTick - 0.67%/0.02%
[02] rest - 0.48%/0.02%
[02] ai - 0.30%/0.01%
[03] unspecified - 73.92%/0.01%
[03] oldAi - 26.08%/0.00%
[02] checkLight - 0.23%/0.01%
[03] checkedPosition < toCheckCount - 61.73%/0.01%
[03] getBrightness - 23.97%/0.00%
[03] unspecified - 14.30%/0.00%
[02] push - 0.19%/0.01%
[02] headTurn - 0.09%/0.00%
[02] rangeChecks - 0.04%/0.00%
[02] jump - 0.03%/0.00%
[02] looting - 0.03%/0.00%
[02] getBrightness - 0.00%/0.00%
[02] checkedPosition < toCheckCount - 0.00%/0.00%
[01] playerTick - 4.75%/0.18%
[02] unspecified - 49.16%/0.09%
[02] travel - 26.77%/0.05%
[03] move - 49.96%/0.02%
[03] unspecified - 32.77%/0.02%
[03] rest - 17.27%/0.01%
[02] entityBaseTick - 11.83%/0.02%
[02] mobBaseTick - 5.92%/0.01%
[02] ai - 3.07%/0.01%
[03] unspecified - 69.86%/0.00%
[03] oldAi - 30.14%/0.00%
[02] push - 1.81%/0.00%
[02] headTurn - 0.83%/0.00%
[02] rangeChecks - 0.25%/0.00%
[02] looting - 0.19%/0.00%
[02] jump - 0.18%/0.00%
[01] unspecified - 1.42%/0.05%
[01] keepAlive - 0.06%/0.00%
[00] save - 0.11%/0.11%
[00] players - 0.00%/0.00%
[00] tallying - 0.00%/0.00%
[00] tickables - 0.00%/0.00%
[00] snooper - 0.00%/0.00%
--- END PROFILE DUMP ---
So it turns out, the player that kept getting disconnected for "genericReason" had recently broken an a great many double chests full of items (accidentally). I am not sure how many chests were involve, but it was an entire storage room. When an op (in creative mode) teleported to the player's location, all of the items were absorbed by the op, thereby solving the issue.
But it would be nice if the Minecraft server could be more descriptive as to the root cause of issues like this. Maybe a warning like: