Wave
  1. Wave
  2. WAVE-312

Not saving editions when concurrent editions in same wave

    Details

      Description

      • Alice: begins editing a blip of a wave. She needs to write a long paragraph.
      • Bob: begins editing a while after Alice, in another blip in the same wave.
      • Alice doesn't see that Bob is writing, nothing new appears
      • Alice finishes editing her wave and moves to another wave.
      • Bobs finishes editing that wave and moves to another wave.
      • When Alice comes back to the same wave, she sees her edition was not fully saved. It saved only until the instant that Bob began editing.
      • When Bob comes back to the wave, he sees nothing of what he wrote was saved.

      Sometimes it shows the mysterious delta error from:
      http://www.mail-archive.com/wave-dev@incubator.apache.org/msg02036.html
      https://issues.apache.org/jira/browse/WAVE-307
      but other times it shows nothing on the log, so don't know if it's directly related or just chance.

      1. fixWave-312.patch
        2 kB
        Yuri Zelikov
      2. raw-nullpointer.log.xz
        149 kB
        Ali Lown

        Issue Links

          Activity

          Hide
          Yuri Zelikov added a comment -

          Thanks for reporting.
          Can you please try to set the thread counts to 1 in server.config and then check if the issue still happens?

          Show
          Yuri Zelikov added a comment - Thanks for reporting. Can you please try to set the thread counts to 1 in server.config and then check if the issue still happens?
          Hide
          Vicente J. Ruiz Jurado added a comment -

          Just done, lets see... A question: Were all threads set to 1 in waveinabox one hour ago?

          Show
          Vicente J. Ruiz Jurado added a comment - Just done, lets see... A question: Were all threads set to 1 in waveinabox one hour ago?
          Hide
          Samer added a comment -

          Yuri: after changing it, it works much better (we can see each others' editions and it fails much less) but still sometimes it keeps happening. Still couldn't replicate the error in a logical sequence, as it seems happening much less and randomly now.

          Show
          Samer added a comment - Yuri: after changing it, it works much better (we can see each others' editions and it fails much less) but still sometimes it keeps happening. Still couldn't replicate the error in a logical sequence, as it seems happening much less and randomly now.
          Hide
          Vicente J. Ruiz Jurado added a comment -

          More info about this issue or maybe related with #307.

          (With all thread settings to 1)

          Sometimes:

          • you reply some wave, adding some blips
          • you open another wave
          • and return to the original and you can see your blip truncated, or even the root blip is truncated, or you can find less blips.

          Seems that some deltas are overwritten/lost.

          Show
          Vicente J. Ruiz Jurado added a comment - More info about this issue or maybe related with #307. (With all thread settings to 1) Sometimes: you reply some wave, adding some blips you open another wave and return to the original and you can see your blip truncated, or even the root blip is truncated, or you can find less blips. Seems that some deltas are overwritten/lost.
          Hide
          Yuri Zelikov added a comment -

          Can you please try to reproduce? I think it might be fixed by patch to other issue.
          Thanks

          Show
          Yuri Zelikov added a comment - Can you please try to reproduce? I think it might be fixed by patch to other issue. Thanks
          Hide
          Samer added a comment -

          The situation is much more stable now, although still some editions are lost, rarely. We cannot manage to reproduce the sequence in which it happens, but it still happens. We know it happened in cases where only one user was editing a specific wave, so it doesn't seem an issue of concurrency with others...

          Show
          Samer added a comment - The situation is much more stable now, although still some editions are lost, rarely. We cannot manage to reproduce the sequence in which it happens, but it still happens. We know it happened in cases where only one user was editing a specific wave, so it doesn't seem an issue of concurrency with others...
          Hide
          Vicente J. Ruiz Jurado added a comment -

          I agree with Samer.

          More info: I see that is more frequent when you open a wave when someone it's editing it a the same time. That is:

          • Alice is editing a Wave
          • Bob sees activity in his search panel and opens the same wave
          • Alice is still editing (thinking that all the her editions are persisted)
          • Bob see that Alice seems that stops to edit in some word/sentence.
          • Alice continue editing, but when she re-opens the wave, all her editions since are lost

          This happens silently, without any "delta" or "concurrent" or other wave error.

          Sometimes, very very less frequent, it happens editing alone without other users concurrent interaction.

          (Wave code it's updated to tip)

          Show
          Vicente J. Ruiz Jurado added a comment - I agree with Samer. More info: I see that is more frequent when you open a wave when someone it's editing it a the same time. That is: Alice is editing a Wave Bob sees activity in his search panel and opens the same wave Alice is still editing (thinking that all the her editions are persisted) Bob see that Alice seems that stops to edit in some word/sentence. Alice continue editing, but when she re-opens the wave, all her editions since are lost This happens silently, without any "delta" or "concurrent" or other wave error. Sometimes, very very less frequent, it happens editing alone without other users concurrent interaction. (Wave code it's updated to tip)
          Hide
          Samer added a comment -

          Error Log in the server side, in several moments this error appeared. Hope this helps:

          19-abr-2012 16:40:21 org.waveprotocol.box.server.frontend.WaveViewSubscription submitResponse
          INFO: Submit resolved on channel ch394
          19-abr-2012 16:40:21 org.waveprotocol.box.server.waveserver.WaveletContainerImpl$2 run
          GRAVE: Version 2095:SWbDxKHL03gH847jCE61DhTu6EU=
          java.util.concurrent.ExecutionException: java.lang.IllegalStateException: position = %d, file=%d, filename=16752 [16746, /var/lib/kune/_deltas/6b756e652e6363_772b6a717034736e64336e3730626b/6b756e652e6363_636f6e762b726f6f74.index]
          at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252)
          at java.util.concurrent.FutureTask.get(FutureTask.java:111)
          at org.waveprotocol.box.server.waveserver.WaveletContainerImpl$2.run(WaveletContainerImpl.java:240)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
          at java.lang.Thread.run(Thread.java:636)
          Caused by: java.lang.IllegalStateException: position = %d, file=%d, filename=16752 [16746, /var/lib/kune/_deltas/6b756e652e6363_772b6a717034736e64336e3730626b/6b756e652e6363_636f6e762b726f6f74.index]
          at com.google.common.base.Preconditions.checkState(Preconditions.java:172)
          at org.waveprotocol.box.server.persistence.file.DeltaIndex.addDelta(DeltaIndex.java:179)
          at org.waveprotocol.box.server.persistence.file.FileDeltaCollection.append(FileDeltaCollection.java:241)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:201)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:177)
          at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
          at java.util.concurrent.FutureTask.run(FutureTask.java:166)
          ... 3 more

          9-abr-2012 16:53:15 org.waveprotocol.box.server.waveserver.WaveServerImpl submitDelta
          INFO: Submit result for [WaveletName kune.cc/w+W6TOrFiAmfD/kune.cc/conv+root] by vjrj@kune.cc applied 1 ops at v: 145 t: 1334847195665
          19-abr-2012 16:53:15 org.waveprotocol.box.server.frontend.WaveViewSubscription submitResponse
          INFO: Submit resolved on channel ch466
          19-abr-2012 16:53:15 org.waveprotocol.box.server.frontend.WaveViewSubscription submitRequest
          INFO: Submit oustandinding on channel ch464
          19-abr-2012 16:53:15 org.waveprotocol.box.server.waveserver.WaveServerImpl submitDelta
          INFO: Submit to [WaveletName kune.cc/w+W6TOrFiAmfD/kune.cc/conv+root] by samer@kune.cc @ 145 with 1 ops
          java.lang.NullPointerException
          at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:187)
          at com.google.common.collect.ImmutableList$Builder.add(ImmutableList.java:584)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.readDeltasInRange(DeltaStoreBasedWaveletState.java:150)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.getTransformedDeltaHistory(DeltaStoreBasedWaveletState.java:350)
          at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.transformSubmittedDelta(WaveletContainerImpl.java:370)
          at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.maybeTransformSubmittedDelta(WaveletContainerImpl.java:356)
          at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.transformAndApplyLocalDelta(LocalWaveletContainerImpl.java:135)
          at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.submitRequest(LocalWaveletContainerImpl.java:93)
          at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitDelta(WaveServerImpl.java:536)
          at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitRequest(WaveServerImpl.java:338)
          at org.waveprotocol.box.server.frontend.ClientFrontendImpl.submitRequest(ClientFrontendImpl.java:215)
          at org.waveprotocol.box.server.frontend.WaveClientRpcImpl.submit(WaveClientRpcImpl.java:164)
          at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc$1.submit(WaveClientRpc.java:4459)
          at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc.callMethod(WaveClientRpc.java:4589)
          at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl.run(ServerRpcControllerImpl.java:200)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
          at java.lang.Thread.run(Thread.java:636)
          19-abr-2012 16:53:15 org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1 run
          INFO: error = java.lang.NullPointerException
          19-abr-2012 16:53:15 org.waveprotocol.box.server.rpc.WebSocketServerChannel s

          GRAVE: Version 1002:kzpgzlAfXc2/r2sRB2H7A2jqMJ0=
          java.util.concurrent.ExecutionException: java.lang.IllegalStateException: position = %d, file=%d, filename=8008 [8002, /var/lib/kune/_deltas/6b756e652e6363_772b5736544f724669416d6644/6b756e652e6363_636f6e762b726f6f74.index]
          at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252)
          at java.util.concurrent.FutureTask.get(FutureTask.java:111)
          at org.waveprotocol.box.server.waveserver.WaveletContainerImpl$2.run(WaveletContainerImpl.java:240)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
          at java.lang.Thread.run(Thread.java:636)
          Caused by: java.lang.IllegalStateException: position = %d, file=%d, filename=8008 [8002, /var/lib/kune/_deltas/6b756e652e6363_772b5736544f724669416d6644/6b756e652e6363_636f6e762b726f6f74.index]
          at com.google.common.base.Preconditions.checkState(Preconditions.java:172)
          at org.waveprotocol.box.server.persistence.file.DeltaIndex.addDelta(DeltaIndex.java:179)
          at org.waveprotocol.box.server.persistence.file.FileDeltaCollection.append(FileDeltaCollection.java:241)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:201)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:177)
          at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
          at java.util.concurrent.FutureTask.run(FutureTask.java:166)
          ... 3 more
          19-abr-2012 17:01:16 org.waveprotocol.box.server.frontend.WaveViewSubscription submitResponse
          INFO: Submit resolved on channel ch481

          Show
          Samer added a comment - Error Log in the server side, in several moments this error appeared. Hope this helps: 19-abr-2012 16:40:21 org.waveprotocol.box.server.frontend.WaveViewSubscription submitResponse INFO: Submit resolved on channel ch394 19-abr-2012 16:40:21 org.waveprotocol.box.server.waveserver.WaveletContainerImpl$2 run GRAVE: Version 2095:SWbDxKHL03gH847jCE61DhTu6EU= java.util.concurrent.ExecutionException: java.lang.IllegalStateException: position = %d, file=%d, filename=16752 [16746, /var/lib/kune/_deltas/6b756e652e6363_772b6a717034736e64336e3730626b/6b756e652e6363_636f6e762b726f6f74.index] at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252) at java.util.concurrent.FutureTask.get(FutureTask.java:111) at org.waveprotocol.box.server.waveserver.WaveletContainerImpl$2.run(WaveletContainerImpl.java:240) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:636) Caused by: java.lang.IllegalStateException: position = %d, file=%d, filename=16752 [16746, /var/lib/kune/_deltas/6b756e652e6363_772b6a717034736e64336e3730626b/6b756e652e6363_636f6e762b726f6f74.index] at com.google.common.base.Preconditions.checkState(Preconditions.java:172) at org.waveprotocol.box.server.persistence.file.DeltaIndex.addDelta(DeltaIndex.java:179) at org.waveprotocol.box.server.persistence.file.FileDeltaCollection.append(FileDeltaCollection.java:241) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:201) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:177) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) ... 3 more 9-abr-2012 16:53:15 org.waveprotocol.box.server.waveserver.WaveServerImpl submitDelta INFO: Submit result for [WaveletName kune.cc/w+W6TOrFiAmfD/kune.cc/conv+root] by vjrj@kune.cc applied 1 ops at v: 145 t: 1334847195665 19-abr-2012 16:53:15 org.waveprotocol.box.server.frontend.WaveViewSubscription submitResponse INFO: Submit resolved on channel ch466 19-abr-2012 16:53:15 org.waveprotocol.box.server.frontend.WaveViewSubscription submitRequest INFO: Submit oustandinding on channel ch464 19-abr-2012 16:53:15 org.waveprotocol.box.server.waveserver.WaveServerImpl submitDelta INFO: Submit to [WaveletName kune.cc/w+W6TOrFiAmfD/kune.cc/conv+root] by samer@kune.cc @ 145 with 1 ops java.lang.NullPointerException at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:187) at com.google.common.collect.ImmutableList$Builder.add(ImmutableList.java:584) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.readDeltasInRange(DeltaStoreBasedWaveletState.java:150) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.getTransformedDeltaHistory(DeltaStoreBasedWaveletState.java:350) at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.transformSubmittedDelta(WaveletContainerImpl.java:370) at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.maybeTransformSubmittedDelta(WaveletContainerImpl.java:356) at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.transformAndApplyLocalDelta(LocalWaveletContainerImpl.java:135) at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.submitRequest(LocalWaveletContainerImpl.java:93) at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitDelta(WaveServerImpl.java:536) at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitRequest(WaveServerImpl.java:338) at org.waveprotocol.box.server.frontend.ClientFrontendImpl.submitRequest(ClientFrontendImpl.java:215) at org.waveprotocol.box.server.frontend.WaveClientRpcImpl.submit(WaveClientRpcImpl.java:164) at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc$1.submit(WaveClientRpc.java:4459) at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc.callMethod(WaveClientRpc.java:4589) at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl.run(ServerRpcControllerImpl.java:200) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:636) 19-abr-2012 16:53:15 org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1 run INFO: error = java.lang.NullPointerException 19-abr-2012 16:53:15 org.waveprotocol.box.server.rpc.WebSocketServerChannel s GRAVE: Version 1002:kzpgzlAfXc2/r2sRB2H7A2jqMJ0= java.util.concurrent.ExecutionException: java.lang.IllegalStateException: position = %d, file=%d, filename=8008 [8002, /var/lib/kune/_deltas/6b756e652e6363_772b5736544f724669416d6644/6b756e652e6363_636f6e762b726f6f74.index] at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252) at java.util.concurrent.FutureTask.get(FutureTask.java:111) at org.waveprotocol.box.server.waveserver.WaveletContainerImpl$2.run(WaveletContainerImpl.java:240) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:636) Caused by: java.lang.IllegalStateException: position = %d, file=%d, filename=8008 [8002, /var/lib/kune/_deltas/6b756e652e6363_772b5736544f724669416d6644/6b756e652e6363_636f6e762b726f6f74.index] at com.google.common.base.Preconditions.checkState(Preconditions.java:172) at org.waveprotocol.box.server.persistence.file.DeltaIndex.addDelta(DeltaIndex.java:179) at org.waveprotocol.box.server.persistence.file.FileDeltaCollection.append(FileDeltaCollection.java:241) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:201) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState$2.call(DeltaStoreBasedWaveletState.java:177) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) ... 3 more 19-abr-2012 17:01:16 org.waveprotocol.box.server.frontend.WaveViewSubscription submitResponse INFO: Submit resolved on channel ch481
          Hide
          Vicente J. Ruiz Jurado added a comment -

          This annoying bug is still present.

          I can reproduce easily using the file store, but I can't with the memory store.

          For some reason the delta retrieved in DeltaStoreBasedWaveletState.readDeltasInRange
          delta = reader.getDelta;
          is null.

          User admin@local.net stay in unsaved state
          INFO: Submit to [WaveletName local.net/w+ueh3s7m50sv7A/local.net/conv+root] by admin@local.net @ 383 with 1 ops
          java.lang.NullPointerException
          at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:187)
          at com.google.common.collect.ImmutableList$Builder.add(ImmutableList.java:584)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.readDeltasInRange(DeltaStoreBasedWaveletState.java:150)
          at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.getTransformedDeltaHistory(DeltaStoreBasedWaveletState.java:354)
          at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.transformSubmittedDelta(WaveletContainerImpl.java:370)
          at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.maybeTransformSubmittedDelta(WaveletContainerImpl.java:356)
          at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.transformAndApplyLocalDelta(LocalWaveletContainerImpl.java:138)
          at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.submitRequest(LocalWaveletContainerImpl.java:96)
          at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitDelta(WaveServerImpl.java:542)
          at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitRequest(WaveServerImpl.java:344)
          at org.waveprotocol.box.server.frontend.ClientFrontendImpl.submitRequest(ClientFrontendImpl.java:194)
          at org.waveprotocol.box.server.frontend.WaveClientRpcImpl.submit(WaveClientRpcImpl.java:164)
          at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc$1.submit(WaveClientRpc.java:4459)
          at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc.callMethod(WaveClientRpc.java:4589)
          at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl.run(ServerRpcControllerImpl.java:200)
          at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
          at java.lang.Thread.run(Thread.java:662)
          30-jul-2012 10:26:52 org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1 run
          INFO: error = java.lang.NullPointerException

          Show
          Vicente J. Ruiz Jurado added a comment - This annoying bug is still present. I can reproduce easily using the file store, but I can't with the memory store. For some reason the delta retrieved in DeltaStoreBasedWaveletState.readDeltasInRange delta = reader.getDelta ; is null. User admin@local.net stay in unsaved state INFO: Submit to [WaveletName local.net/w+ueh3s7m50sv7A/local.net/conv+root] by admin@local.net @ 383 with 1 ops java.lang.NullPointerException at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:187) at com.google.common.collect.ImmutableList$Builder.add(ImmutableList.java:584) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.readDeltasInRange(DeltaStoreBasedWaveletState.java:150) at org.waveprotocol.box.server.waveserver.DeltaStoreBasedWaveletState.getTransformedDeltaHistory(DeltaStoreBasedWaveletState.java:354) at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.transformSubmittedDelta(WaveletContainerImpl.java:370) at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.maybeTransformSubmittedDelta(WaveletContainerImpl.java:356) at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.transformAndApplyLocalDelta(LocalWaveletContainerImpl.java:138) at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.submitRequest(LocalWaveletContainerImpl.java:96) at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitDelta(WaveServerImpl.java:542) at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitRequest(WaveServerImpl.java:344) at org.waveprotocol.box.server.frontend.ClientFrontendImpl.submitRequest(ClientFrontendImpl.java:194) at org.waveprotocol.box.server.frontend.WaveClientRpcImpl.submit(WaveClientRpcImpl.java:164) at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc$1.submit(WaveClientRpc.java:4459) at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc.callMethod(WaveClientRpc.java:4589) at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl.run(ServerRpcControllerImpl.java:200) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) 30-jul-2012 10:26:52 org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1 run INFO: error = java.lang.NullPointerException
          Hide
          Yuri Zelikov added a comment -

          I ll check it again, thanks for reporting.

          Show
          Yuri Zelikov added a comment - I ll check it again, thanks for reporting.
          Hide
          Yuri Zelikov added a comment -

          Strange, I can't reproduce it.

          Show
          Yuri Zelikov added a comment - Strange, I can't reproduce it.
          Hide
          Yuri Zelikov added a comment -

          @Vicente
          Can you please try the attached patch if it helps?

          Show
          Yuri Zelikov added a comment - @Vicente Can you please try the attached patch if it helps?
          Hide
          Yuri Zelikov added a comment -

          Patch to test.

          Show
          Yuri Zelikov added a comment - Patch to test.
          Hide
          Ali Lown added a comment -

          @Yuri:
          Here is a raw logfile straight from the server. I have compressed it with xz from 17MB to 152KB.
          The log-file covers history from 12:46:01 to 1:08:25 (yes, my log-files get huge on the server until I compress them)
          One of the above NullPointerException's can be found at line 30523
          A quick 'wc -l' says that the 'Failed to transmit message' error appears 4975 times in that file.
          Feel free to browse, and you will definitely want to use 'grep -v' to filter out a lot of the useless lines (searching etc.)

          Show
          Ali Lown added a comment - @Yuri: Here is a raw logfile straight from the server. I have compressed it with xz from 17MB to 152KB. The log-file covers history from 12:46:01 to 1:08:25 (yes, my log-files get huge on the server until I compress them) One of the above NullPointerException's can be found at line 30523 A quick 'wc -l' says that the 'Failed to transmit message' error appears 4975 times in that file. Feel free to browse, and you will definitely want to use 'grep -v' to filter out a lot of the useless lines (searching etc.)
          Hide
          Yuri Zelikov added a comment -

          It seems to be an issue with the browser closing the websocket. And then Socket.IO tries to write the socket - but fails. The websocket is closed with error 1006. This error is called CLOSE_ABNORMAL and described as follows (MDN/RFC 6455):
          Reserved. Used to indicate that a connection was closed abnormally (that is, with no close frame being sent) when a status code is expected.

          Anyway, I don't know what can cause the issue, but the problem is related to websockets - possibly for the browsers websocket implementations. Maybe the issue happens only on some (older?) browsers. We can try to reproduce the problem and watch if some JS errors are displayed in the browser console.
          -------------------
          INFO: websocket disconnected (1006 - closed): org.waveprotocol.box.server.rpc.WebSocketServerChannel@77952afd
          ...
          Jul 26, 2012 11:41:53 AM org.waveprotocol.box.server.rpc.WebSocketChannel sendMessage
          WARNING: Failed to transmit message on socket, sequence number 10, message
          java.io.IOException: Connection reset by peer
          at sun.nio.ch.FileDispatcher.write0(Native Method)
          at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
          at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:122)
          at sun.nio.ch.IOUtil.write(IOUtil.java:78)
          at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:352)
          at org.eclipse.jetty.io.nio.ChannelEndPoint.flush(ChannelEndPoint.java:292)
          at org.eclipse.jetty.io.nio.SelectChannelEndPoint.flush(SelectChannelEndPoint.java:344)
          ------------------

          ---------------
          INFO: Submit to [WaveletName waveinabox.net/w+gY-qNfER1lA/waveinabox.net/conv+root] by plushy@waveinabox.net @ 262 with 2 ops
          Jul 29, 2012 9:35:40 AM org.waveprotocol.box.server.rpc.WebSocketChannel sendMessage
          WARNING: Failed to transmit message on socket, sequence number 1, message wavelet_name: "waveinabox.net/w+gY-qNfER1lA/~/conv+root"
          applied_delta {
          hashed_version

          { version: 262 history_hash: "" }

          author: "plushy@waveinabox.net"
          operation {
          mutate_document {
          document_id: "conversation"
          document_operation {
          component

          { retain_item_count: 9 }

          component {
          element_start {
          type: "blip"
          attribute

          { key: "id" value: "b+dKyEpzt2jTA" }

          }
          }
          component

          { element_end: true }

          component

          { retain_item_count: 1 }

          }
          }
          }
          operation {
          mutate_document {
          document_id: "b+dKyEpzt2jTA"
          document_operation {
          component {
          annotation_boundary {
          change

          { key: "user/d/dKyEpzt2jT" new_value: "plushy@waveinabox.net,1343554540345," }

          }
          }
          component

          { retain_item_count: 3 }

          component {
          annotation_boundary {
          change

          { key: "user/e/dKyEpzt2jT" new_value: "plushy@waveinabox.net" }

          }
          }
          component

          { retain_item_count: 1 }

          component {
          annotation_boundary

          { end: "user/d/dKyEpzt2jT" end: "user/e/dKyEpzt2jT" }

          }
          }
          }
          }
          }
          resulting_version

          { version: 264 history_hash: "\370\2045\206(lF\230\334sX\024\230\356\324\301\030\220h\221" }

          channel_id: "ch1015"

          com.glines.socketio.common.SocketIOException: org.eclipse.jetty.io.EofException
          at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:160)
          at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:194)
          at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:186)
          at org.waveprotocol.box.server.rpc.SocketIOServerChannel.sendMessageString(SocketIOServerChannel.java:97)
          at org.waveprotocol.box.server.rpc.WebSocketChannel.sendMessage(WebSocketChannel.java:143)
          at org.waveprotocol.box.server.rpc.ServerRpcProvider$SocketIOConnection.sendMessage(ServerRpcProvider.java:173)
          at org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1.run(ServerRpcProvider.java:276)
          at org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1.run(ServerRpcProvider.java:262)
          at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl$1.run(ServerRpcControllerImpl.java:191)
          at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl$1.run(ServerRpcControllerImpl.java:166)
          at org.waveprotocol.box.server.frontend.WaveClientRpcImpl$1.onUpdate(WaveClientRpcImpl.java:141)
          at org.waveprotocol.box.server.frontend.WaveViewSubscription.sendUpdate(WaveViewSubscription.java:191)
          at org.waveprotocol.box.server.frontend.WaveViewSubscription.onUpdate(WaveViewSubscription.java:149)
          at org.waveprotocol.box.server.frontend.UserManager.onUpdate(UserManager.java:76)
          at org.waveprotocol.box.server.frontend.ClientFrontendImpl.participantUpdate(ClientFrontendImpl.java:235)
          at org.waveprotocol.box.server.frontend.ClientFrontendImpl.waveletUpdate(ClientFrontendImpl.java:280)
          at org.waveprotocol.box.server.waveserver.WaveletNotificationDispatcher.waveletUpdate(WaveletNotificationDispatcher.java:125)
          at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.notifyOfDeltas(WaveletContainerImpl.java:181)
          at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.submitRequest(LocalWaveletContainerImpl.java:107)
          at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitDelta(WaveServerImpl.java:542)
          at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitRequest(WaveServerImpl.java:344)
          at org.waveprotocol.box.server.frontend.ClientFrontendImpl.submitRequest(ClientFrontendImpl.java:194)
          at org.waveprotocol.box.server.frontend.WaveClientRpcImpl.submit(WaveClientRpcImpl.java:164)
          at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc$1.submit(WaveClientRpc.java:4459)
          at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc.callMethod(WaveClientRpc.java:4589)
          at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl.run(ServerRpcControllerImpl.java:200)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
          at java.lang.Thread.run(Thread.java:679)
          Caused by: org.eclipse.jetty.io.EofException
          at org.eclipse.jetty.http.HttpGenerator.flushBuffer(HttpGenerator.java:939)
          at org.eclipse.jetty.server.AbstractHttpConnection.flushResponse(AbstractHttpConnection.java:618)
          at org.eclipse.jetty.server.Response.flushBuffer(Response.java:1025)
          at com.glines.socketio.server.transport.XHRMultipartDataHandler.onWriteData(XHRMultipartDataHandler.java:94)
          at com.glines.socketio.server.transport.jetty.ConnectionTimeoutPreventerDataHandler.onWriteData(ConnectionTimeoutPreventerDataHandler.java:77)
          at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:158)
          ... 28 more
          Caused by: java.io.IOException: Broken pipe
          -----------------------------------------------------------

          Show
          Yuri Zelikov added a comment - It seems to be an issue with the browser closing the websocket. And then Socket.IO tries to write the socket - but fails. The websocket is closed with error 1006. This error is called CLOSE_ABNORMAL and described as follows (MDN/RFC 6455): Reserved. Used to indicate that a connection was closed abnormally (that is, with no close frame being sent) when a status code is expected. Anyway, I don't know what can cause the issue, but the problem is related to websockets - possibly for the browsers websocket implementations. Maybe the issue happens only on some (older?) browsers. We can try to reproduce the problem and watch if some JS errors are displayed in the browser console. ------------------- INFO: websocket disconnected (1006 - closed): org.waveprotocol.box.server.rpc.WebSocketServerChannel@77952afd ... Jul 26, 2012 11:41:53 AM org.waveprotocol.box.server.rpc.WebSocketChannel sendMessage WARNING: Failed to transmit message on socket, sequence number 10, message java.io.IOException: Connection reset by peer at sun.nio.ch.FileDispatcher.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:122) at sun.nio.ch.IOUtil.write(IOUtil.java:78) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:352) at org.eclipse.jetty.io.nio.ChannelEndPoint.flush(ChannelEndPoint.java:292) at org.eclipse.jetty.io.nio.SelectChannelEndPoint.flush(SelectChannelEndPoint.java:344) ------------------ --------------- INFO: Submit to [WaveletName waveinabox.net/w+gY-qNfER1lA/waveinabox.net/conv+root] by plushy@waveinabox.net @ 262 with 2 ops Jul 29, 2012 9:35:40 AM org.waveprotocol.box.server.rpc.WebSocketChannel sendMessage WARNING: Failed to transmit message on socket, sequence number 1, message wavelet_name: "waveinabox.net/w+gY-qNfER1lA/~/conv+root" applied_delta { hashed_version { version: 262 history_hash: "" } author: "plushy@waveinabox.net" operation { mutate_document { document_id: "conversation" document_operation { component { retain_item_count: 9 } component { element_start { type: "blip" attribute { key: "id" value: "b+dKyEpzt2jTA" } } } component { element_end: true } component { retain_item_count: 1 } } } } operation { mutate_document { document_id: "b+dKyEpzt2jTA" document_operation { component { annotation_boundary { change { key: "user/d/dKyEpzt2jT" new_value: "plushy@waveinabox.net,1343554540345," } } } component { retain_item_count: 3 } component { annotation_boundary { change { key: "user/e/dKyEpzt2jT" new_value: "plushy@waveinabox.net" } } } component { retain_item_count: 1 } component { annotation_boundary { end: "user/d/dKyEpzt2jT" end: "user/e/dKyEpzt2jT" } } } } } } resulting_version { version: 264 history_hash: "\370\2045\206(lF\230\334sX\024\230\356\324\301\030\220h\221" } channel_id: "ch1015" com.glines.socketio.common.SocketIOException: org.eclipse.jetty.io.EofException at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:160) at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:194) at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:186) at org.waveprotocol.box.server.rpc.SocketIOServerChannel.sendMessageString(SocketIOServerChannel.java:97) at org.waveprotocol.box.server.rpc.WebSocketChannel.sendMessage(WebSocketChannel.java:143) at org.waveprotocol.box.server.rpc.ServerRpcProvider$SocketIOConnection.sendMessage(ServerRpcProvider.java:173) at org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1.run(ServerRpcProvider.java:276) at org.waveprotocol.box.server.rpc.ServerRpcProvider$Connection$1.run(ServerRpcProvider.java:262) at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl$1.run(ServerRpcControllerImpl.java:191) at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl$1.run(ServerRpcControllerImpl.java:166) at org.waveprotocol.box.server.frontend.WaveClientRpcImpl$1.onUpdate(WaveClientRpcImpl.java:141) at org.waveprotocol.box.server.frontend.WaveViewSubscription.sendUpdate(WaveViewSubscription.java:191) at org.waveprotocol.box.server.frontend.WaveViewSubscription.onUpdate(WaveViewSubscription.java:149) at org.waveprotocol.box.server.frontend.UserManager.onUpdate(UserManager.java:76) at org.waveprotocol.box.server.frontend.ClientFrontendImpl.participantUpdate(ClientFrontendImpl.java:235) at org.waveprotocol.box.server.frontend.ClientFrontendImpl.waveletUpdate(ClientFrontendImpl.java:280) at org.waveprotocol.box.server.waveserver.WaveletNotificationDispatcher.waveletUpdate(WaveletNotificationDispatcher.java:125) at org.waveprotocol.box.server.waveserver.WaveletContainerImpl.notifyOfDeltas(WaveletContainerImpl.java:181) at org.waveprotocol.box.server.waveserver.LocalWaveletContainerImpl.submitRequest(LocalWaveletContainerImpl.java:107) at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitDelta(WaveServerImpl.java:542) at org.waveprotocol.box.server.waveserver.WaveServerImpl.submitRequest(WaveServerImpl.java:344) at org.waveprotocol.box.server.frontend.ClientFrontendImpl.submitRequest(ClientFrontendImpl.java:194) at org.waveprotocol.box.server.frontend.WaveClientRpcImpl.submit(WaveClientRpcImpl.java:164) at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc$1.submit(WaveClientRpc.java:4459) at org.waveprotocol.box.common.comms.WaveClientRpc$ProtocolWaveClientRpc.callMethod(WaveClientRpc.java:4589) at org.waveprotocol.box.server.rpc.ServerRpcControllerImpl.run(ServerRpcControllerImpl.java:200) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:679) Caused by: org.eclipse.jetty.io.EofException at org.eclipse.jetty.http.HttpGenerator.flushBuffer(HttpGenerator.java:939) at org.eclipse.jetty.server.AbstractHttpConnection.flushResponse(AbstractHttpConnection.java:618) at org.eclipse.jetty.server.Response.flushBuffer(Response.java:1025) at com.glines.socketio.server.transport.XHRMultipartDataHandler.onWriteData(XHRMultipartDataHandler.java:94) at com.glines.socketio.server.transport.jetty.ConnectionTimeoutPreventerDataHandler.onWriteData(ConnectionTimeoutPreventerDataHandler.java:77) at com.glines.socketio.server.transport.jetty.JettyContinuationTransportHandler.sendMessage(JettyContinuationTransportHandler.java:158) ... 28 more Caused by: java.io.IOException: Broken pipe -----------------------------------------------------------

            People

            • Assignee:
              Yuri Zelikov
              Reporter:
              Samer
            • Votes:
              1 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:

                Development