Thread: dataselect wrong data returned to multithreaded client

Started: 2012-07-16 23:29:55
Last activity: 2012-07-21 00:32:46
Topics: Web Services
Philip Crotwell
2012-07-16 23:29:55
Hi

I have been doing some tests with the dataselect web service from a
multithreaded client (SOD) and found that occasionally I would get
data records back in one thread that were not the channel asked for.
Luckily I had a check in place from some earlier issues that compared
the channel codes in the request with those in the result. Here is an
example. It appears that the thread that requested data from BORG got
data from ARU.


2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
match channelid in request.
req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

The request, if it helps, was
net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

This is a bit scary as I suspect many clients do not check the
returned data to make sure it actually corresponds to their original
request. I have not seen this with a single threaded client, so
perhaps that is a clue.

I will try to do some more testing and see if I can provide any more details.

thanks,
Philip

  • Hi all,

    I see a possibly related problem with channel inclination. The
    following request should return a BHZ channel, but the component
    inclination in the sac header is 90.0 - my understanding from the SAC
    manual is that this should be 0.0 for Z component UP:

    CMPINC F Component incident angle (degrees from vertical).

    http://www.iris.edu/ws/timeseries/query?net=IU&sta=MAKZ&loc=00&cha=BHZ&start=2012-07-17T07:28:26.02&dur=844&output=sacbl

    Part of the sac header.

    CMPAZ = 0.0
    CMPINC = 90.0
    KSTNM = MAKZ
    KCMPNM = BHZ
    KNETWK = IU

    Thanks,

    Anthony


    On 2012/07/16 22:29, Philip Crotwell wrote:
    Hi

    I have been doing some tests with the dataselect web service from a
    multithreaded client (SOD) and found that occasionally I would get
    data records back in one thread that were not the channel asked for.
    Luckily I had a check in place from some earlier issues that compared
    the channel codes in the request with those in the result. Here is an
    example. It appears that the thread that requested data from BORG got
    data from ARU.


    2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
    match channelid in request.
    req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
    seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

    The request, if it helps, was
    net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

    This is a bit scary as I suspect many clients do not check the
    returned data to make sure it actually corresponds to their original
    request. I have not seen this with a single threaded client, so
    perhaps that is a clue.

    I will try to do some more testing and see if I can provide any more details.

    thanks,
    Philip
    _______________________________________________
    webservices mailing list
    webservices<at>iris.washington.edu
    http://www.iris.washington.edu/mailman/listinfo/webservices


    --
    Sent from my iClayTablet

    ------------------------------------------------------------------------

    *Anthony Lomax*
    *161 Allée du Micocoulier, 06370 Mouans-Sartoux, France*
    *tel: +33 (0)4 93 75 25 02 e-mail: anthony<at>alomax.net
    <anthony<at>alomax.net> web: http://www.alomax.net
    http://www.alomax.net/ *

    *Science & Special Topics: * *http://www.alomax.net/science*
    *ALomax Scientific: * *http://www.alomax.net/alss*
    ------------------------------------------------------------------------



    • Anthony:

      Thanks for pointing out the problem with the incorrect component incident angles.

      This problem was caused by a typo in the source code for the ws-tracedsp webservice.
      Buried in the code, "depth" was being used instead of "dip" !

      Sorry about that.

      The problem has been fixed in the new version of ws-tracedsp (1.4.5) which is now in production.
      This in turn fixes the problem win ws-timeseries.

      There is no reason to believe that this issues is related to the problem that Philip Crotwell reported (see below).

      Please note: cached data on our side may continue to report incorrect values for the hour until the cache is flushed out.

      Cheers,

      Bruce Weertman

      --------------------------------------
      Software Engineer
      IRIS DMC
      1408 NE 45h St, Suite 201
      Seattle, WA 98105

      bruce<at>iris.washington.edu
      (206) 547-0393


      On Jul 17, 2012, at 12:51 AM, Anthony Lomax wrote:

      Hi all,

      I see a possibly related problem with channel inclination. The following request should return a BHZ channel, but the component inclination in the sac header is 90.0 - my understanding from the SAC manual is that this should be 0.0 for Z component UP:

      CMPINC F Component incident angle (degrees from vertical).

      http://www.iris.edu/ws/timeseries/query?net=IU&sta=MAKZ&loc=00&cha=BHZ&start=2012-07-17T07:28:26.02&dur=844&output=sacbl

      Part of the sac header.

      CMPAZ = 0.0
      CMPINC = 90.0
      KSTNM = MAKZ
      KCMPNM = BHZ
      KNETWK = IU

      Thanks,

      Anthony


      On 2012/07/16 22:29, Philip Crotwell wrote:
      Hi

      I have been doing some tests with the dataselect web service from a
      multithreaded client (SOD) and found that occasionally I would get
      data records back in one thread that were not the channel asked for.
      Luckily I had a check in place from some earlier issues that compared
      the channel codes in the request with those in the result. Here is an
      example. It appears that the thread that requested data from BORG got
      data from ARU.


      2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
      match channelid in request.
      req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
      seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

      The request, if it helps, was
      net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

      This is a bit scary as I suspect many clients do not check the
      returned data to make sure it actually corresponds to their original
      request. I have not seen this with a single threaded client, so
      perhaps that is a clue.

      I will try to do some more testing and see if I can provide any more details.

      thanks,
      Philip
      _______________________________________________
      webservices mailing list

      webservices<at>iris.washington.edu
      http://www.iris.washington.edu/mailman/listinfo/webservices




      --
      Sent from my iClayTablet


      Anthony Lomax
      161 Allée du Micocoulier, 06370 Mouans-Sartoux, France
      tel: +33 (0)4 93 75 25 02 e-mail: anthony<at>alomax.net web: http://www.alomax.net

      Science & Special Topics: http://www.alomax.net/science
      ALomax Scientific: http://www.alomax.net/alss


      _______________________________________________
      webservices mailing list
      webservices<at>iris.washington.edu
      http://www.iris.washington.edu/mailman/listinfo/webservices




      • Hello Bruce,

        Thanks for the information and quick fix. I have checked a few traces
        and all show correctly the Z component inclination.

        Great!

        Ciao,

        Anthony

        On 2012/07/17 20:10, Bruce Weertman wrote:
        Anthony:

        Thanks for pointing out the problem with the incorrect component incident angles.

        This problem was caused by a typo in the source code for the ws-tracedsp webservice.
        Buried in the code, "depth" was being used instead of "dip" !

        Sorry about that.

        The problem has been fixed in the new version of ws-tracedsp (1.4.5) which is now in production.
        This in turn fixes the problem win ws-timeseries.

        There is no reason to believe that this issues is related to the problem that Philip Crotwell reported (see below).

        Please note: cached data on our side may continue to report incorrect values for the hour until the cache is flushed out.

        Cheers,

        Bruce Weertman

        --------------------------------------
        Software Engineer
        IRIS DMC
        1408 NE 45h St, Suite 201
        Seattle, WA 98105

        bruce<at>iris.washington.edu
        (206) 547-0393


        On Jul 17, 2012, at 12:51 AM, Anthony Lomax wrote:

        Hi all,

        I see a possibly related problem with channel inclination. The following request should return a BHZ channel, but the component inclination in the sac header is 90.0 - my understanding from the SAC manual is that this should be 0.0 for Z component UP:

        CMPINC F Component incident angle (degrees from vertical).

        http://www.iris.edu/ws/timeseries/query?net=IU&sta=MAKZ&loc=00&cha=BHZ&start=2012-07-17T07:28:26.02&dur=844&output=sacbl

        Part of the sac header.

        CMPAZ = 0.0
        CMPINC = 90.0
        KSTNM = MAKZ
        KCMPNM = BHZ
        KNETWK = IU

        Thanks,

        Anthony


        On 2012/07/16 22:29, Philip Crotwell wrote:
        Hi

        I have been doing some tests with the dataselect web service from a
        multithreaded client (SOD) and found that occasionally I would get
        data records back in one thread that were not the channel asked for.
        Luckily I had a check in place from some earlier issues that compared
        the channel codes in the request with those in the result. Here is an
        example. It appears that the thread that requested data from BORG got
        data from ARU.


        2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
        match channelid in request.
        req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
        seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

        The request, if it helps, was
        net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

        This is a bit scary as I suspect many clients do not check the
        returned data to make sure it actually corresponds to their original
        request. I have not seen this with a single threaded client, so
        perhaps that is a clue.

        I will try to do some more testing and see if I can provide any more details.

        thanks,
        Philip
        _______________________________________________
        webservices mailing list

        webservices<at>iris.washington.edu
        http://www.iris.washington.edu/mailman/listinfo/webservices



        --
        Sent from my iClayTablet


        Anthony Lomax
        161 Allée du Micocoulier, 06370 Mouans-Sartoux, France
        tel: +33 (0)4 93 75 25 02 e-mail: anthony<at>alomax.net web: http://www.alomax.net

        Science & Special Topics: http://www.alomax.net/science
        ALomax Scientific: http://www.alomax.net/alss


        _______________________________________________
        webservices mailing list
        webservices<at>iris.washington.edu
        http://www.iris.washington.edu/mailman/listinfo/webservices


        _______________________________________________
        webservices mailing list
        webservices<at>iris.washington.edu
        http://www.iris.washington.edu/mailman/listinfo/webservices


        --
        Sent from my iClayTablet

        ------------------------------------------------------------------------

        *Anthony Lomax*
        *161 Allée du Micocoulier, 06370 Mouans-Sartoux, France*
        *tel: +33 (0)4 93 75 25 02 e-mail: anthony<at>alomax.net
        <anthony<at>alomax.net> web: http://www.alomax.net
        http://www.alomax.net/ *

        *Science & Special Topics: * *http://www.alomax.net/science*
        *ALomax Scientific: * *http://www.alomax.net/alss*
        ------------------------------------------------------------------------



        • Philip:

          Just to get back to you - and everybody else on the list.

          Are you saying is thread-1 and thread-2 are each making requests, but thread-1 gets the data that thread-2 made.

          Or something along that line?

          Possibilities:

          (1) Collision of token values. Token is generated from the request via a standard hashing algorithm.

          (2) In the java servlet one request gets confused with another request. This could happen if there was a mistake
          where the wrong scope was used for variables. For example improperly using variables from the servlet instance and not off
          of the stack or accidentally using a global (ie static) variable. Code review looks OK. But that's just code review.

          (3) Some sort of weird networking issue related to reusing http connections??

          I wrote a script to scan the cache (had 34,000 items in it) looking for a mis-match between the data and the requests,
          but I didn't find any. A necessary but not sufficient test of the cache working properly.


          Are you saying that you saw these requests collide
          http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
          http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

          I don't see that:

          geodude:tmp bruce$ wget -O aru.dat "http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
          --2012-07-19 10:19:45-- http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
          Resolving www.iris.edu... 128.95.166.129
          Connecting to www.iris.edu|128.95.166.129|:80... connected.
          HTTP request sent, awaiting response... 200 OK
          Length: 28672 (28K) [application/vnd.fdsn.mseed]
          Saving to: `aru.dat'

          100%[==================================================================================================================================================================>] 28,672 --.-K/s in 0.002s

          2012-07-19 10:19:45 (11.3 MB/s) - `aru.dat' saved [28672/28672]

          geodude:tmp bruce$ msi aru.dat
          II_ARU_00_BHZ, 000001, M, 4096, 2894 samples, 19.99993515 Hz, 2009,136,01:08:44.015300
          II_ARU_00_BHZ, 000000, M, 4096, 3104 samples, 19.99993515 Hz, 2009,136,01:11:08.715900
          II_ARU_00_BHZ, 000000, M, 4096, 3446 samples, 19.99993515 Hz, 2009,136,01:13:43.916400
          II_ARU_00_BHZ, 000000, M, 4096, 3520 samples, 19.99993515 Hz, 2009,136,01:16:36.217000
          II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz, 2009,136,01:19:32.217500
          II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz, 2009,136,01:22:37.818100
          II_ARU_00_BHZ, 000001, M, 4096, 852 samples, 19.99993515 Hz, 2009,136,01:25:43.418700


          geodude:tmp bruce$ wget -O borg.dat "http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
          --2012-07-19 10:18:51-- http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
          Resolving www.iris.edu... 128.95.166.129
          Connecting to www.iris.edu|128.95.166.129|:80... connected.
          HTTP request sent, awaiting response... 200 OK
          Length: 45056 (44K) [application/vnd.fdsn.mseed]
          Saving to: `borg.dat'

          100%[==================================================================================================================================================================>] 45,056 --.-K/s in 0.004s

          geodude:tmp bruce$ msi borg.dat
          II_BORG_00_BHZ, 000001, M, 4096, 762 samples, 20 Hz, 2009,136,01:08:44.049900
          II_BORG_00_BHZ, 000000, M, 4096, 2204 samples, 20 Hz, 2009,136,01:09:22.149900
          II_BORG_00_BHZ, 000000, M, 4096, 2120 samples, 20 Hz, 2009,136,01:11:12.349900
          II_BORG_00_BHZ, 000000, M, 4096, 2024 samples, 20 Hz, 2009,136,01:12:58.349900
          II_BORG_00_BHZ, 000000, M, 4096, 2170 samples, 20 Hz, 2009,136,01:14:39.549900
          II_BORG_00_BHZ, 000000, M, 4096, 2122 samples, 20 Hz, 2009,136,01:16:28.049900
          II_BORG_00_BHZ, 000000, M, 4096, 2100 samples, 20 Hz, 2009,136,01:18:14.149900
          II_BORG_00_BHZ, 000000, M, 4096, 2142 samples, 20 Hz, 2009,136,01:19:59.149900
          II_BORG_00_BHZ, 000000, M, 4096, 2172 samples, 20 Hz, 2009,136,01:21:46.249900
          II_BORG_00_BHZ, 000000, M, 4096, 2138 samples, 20 Hz, 2009,136,01:23:34.849900
          II_BORG_00_BHZ, 000001, M, 4096, 1286 samples, 20 Hz, 2009,136,01:25:21.749900

          Any more information would be appreciated.

          Thanks,
          -Bruce


          Begin forwarded message:



          On 2012/07/16 22:29, Philip Crotwell wrote:
          Hi

          I have been doing some tests with the dataselect web service from a
          multithreaded client (SOD) and found that occasionally I would get
          data records back in one thread that were not the channel asked for.
          Luckily I had a check in place from some earlier issues that compared
          the channel codes in the request with those in the result. Here is an
          example. It appears that the thread that requested data from BORG got
          data from ARU.


          2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
          match channelid in request.
          req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
          seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

          The request, if it helps, was
          net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

          This is a bit scary as I suspect many clients do not check the
          returned data to make sure it actually corresponds to their original
          request. I have not seen this with a single threaded client, so
          perhaps that is a clue.

          I will try to do some more testing and see if I can provide any more details.

          thanks,
          Philip
          _______________________________________________
          webservices mailing list

          webservices<at>iris.washington.edu
          http://www.iris.washington.edu/mailman/listinfo/webservices





          --------------------------------------
          Bruce R Weertman
          Software Engineer
          IRIS DMC
          1408 NE 45h St, Suite 201
          Seattle, WA 98105

          bruce<at>iris.washington.edu
          (206) 547-0393


          • Hi

            I don't think I can tell if it was a collision or not. All I know is
            that one request in one thread got data for a different station. It is
            true that another thread on my end asked for data from that other
            station at a similar time, but I am not sure if it was actually
            coincidental or not. Because I was doing a test using many threads on
            my end (and hence many http connections), I assumed that it was caused
            by that, but I actually don't know. Given I can't seem to reproduce
            it, I am not sure what to say.

            I am leaving the "is the answer from the same station as the request"
            check in my code, so hopefully I will notice if it happens again.

            Debugging stuff that you can't reproduce is somewhere between really,
            really hard and impossible!

            thanks,
            Philip


            On Thu, Jul 19, 2012 at 1:53 PM, Bruce Weertman
            <bruce<at>iris.washington.edu> wrote:
            Philip:

            Just to get back to you - and everybody else on the list.

            Are you saying is thread-1 and thread-2 are each making requests, but
            thread-1 gets the data that thread-2 made.

            Or something along that line?

            Possibilities:

            (1) Collision of token values. Token is generated from the request via a
            standard hashing algorithm.

            (2) In the java servlet one request gets confused with another request. This
            could happen if there was a mistake
            where the wrong scope was used for variables. For example improperly using
            variables from the servlet instance and not off
            of the stack or accidentally using a global (ie static) variable. Code
            review looks OK. But that's just code review.

            (3) Some sort of weird networking issue related to reusing http
            connections??

            I wrote a script to scan the cache (had 34,000 items in it) looking for a
            mis-match between the data and the requests,
            but I didn't find any. A necessary but not sufficient test of the cache
            working properly.


            Are you saying that you saw these requests collide
            http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
            http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

            I don't see that:

            geodude:tmp bruce$ wget -O aru.dat
            "http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
            --2012-07-19 10:19:45--
            http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
            Resolving www.iris.edu... 128.95.166.129
            Connecting to www.iris.edu|128.95.166.129|:80... connected.
            HTTP request sent, awaiting response... 200 OK
            Length: 28672 (28K) [application/vnd.fdsn.mseed]
            Saving to: `aru.dat'

            100%[==================================================================================================================================================================>]
            28,672 --.-K/s in 0.002s

            2012-07-19 10:19:45 (11.3 MB/s) - `aru.dat' saved [28672/28672]

            geodude:tmp bruce$ msi aru.dat
            II_ARU_00_BHZ, 000001, M, 4096, 2894 samples, 19.99993515 Hz,
            2009,136,01:08:44.015300
            II_ARU_00_BHZ, 000000, M, 4096, 3104 samples, 19.99993515 Hz,
            2009,136,01:11:08.715900
            II_ARU_00_BHZ, 000000, M, 4096, 3446 samples, 19.99993515 Hz,
            2009,136,01:13:43.916400
            II_ARU_00_BHZ, 000000, M, 4096, 3520 samples, 19.99993515 Hz,
            2009,136,01:16:36.217000
            II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz,
            2009,136,01:19:32.217500
            II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz,
            2009,136,01:22:37.818100
            II_ARU_00_BHZ, 000001, M, 4096, 852 samples, 19.99993515 Hz,
            2009,136,01:25:43.418700


            geodude:tmp bruce$ wget -O borg.dat
            "http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
            --2012-07-19 10:18:51--
            http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
            Resolving www.iris.edu... 128.95.166.129
            Connecting to www.iris.edu|128.95.166.129|:80... connected.
            HTTP request sent, awaiting response... 200 OK
            Length: 45056 (44K) [application/vnd.fdsn.mseed]
            Saving to: `borg.dat'

            100%[==================================================================================================================================================================>]
            45,056 --.-K/s in 0.004s

            geodude:tmp bruce$ msi borg.dat
            II_BORG_00_BHZ, 000001, M, 4096, 762 samples, 20 Hz,
            2009,136,01:08:44.049900
            II_BORG_00_BHZ, 000000, M, 4096, 2204 samples, 20 Hz,
            2009,136,01:09:22.149900
            II_BORG_00_BHZ, 000000, M, 4096, 2120 samples, 20 Hz,
            2009,136,01:11:12.349900
            II_BORG_00_BHZ, 000000, M, 4096, 2024 samples, 20 Hz,
            2009,136,01:12:58.349900
            II_BORG_00_BHZ, 000000, M, 4096, 2170 samples, 20 Hz,
            2009,136,01:14:39.549900
            II_BORG_00_BHZ, 000000, M, 4096, 2122 samples, 20 Hz,
            2009,136,01:16:28.049900
            II_BORG_00_BHZ, 000000, M, 4096, 2100 samples, 20 Hz,
            2009,136,01:18:14.149900
            II_BORG_00_BHZ, 000000, M, 4096, 2142 samples, 20 Hz,
            2009,136,01:19:59.149900
            II_BORG_00_BHZ, 000000, M, 4096, 2172 samples, 20 Hz,
            2009,136,01:21:46.249900
            II_BORG_00_BHZ, 000000, M, 4096, 2138 samples, 20 Hz,
            2009,136,01:23:34.849900
            II_BORG_00_BHZ, 000001, M, 4096, 1286 samples, 20 Hz,
            2009,136,01:25:21.749900

            Any more information would be appreciated.

            Thanks,
            -Bruce


            Begin forwarded message:



            On 2012/07/16 22:29, Philip Crotwell wrote:

            Hi

            I have been doing some tests with the dataselect web service from a
            multithreaded client (SOD) and found that occasionally I would get
            data records back in one thread that were not the channel asked for.
            Luckily I had a check in place from some earlier issues that compared
            the channel codes in the request with those in the result. Here is an
            example. It appears that the thread that requested data from BORG got
            data from ARU.


            2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
            match channelid in request.
            req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
            seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

            The request, if it helps, was
            net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

            This is a bit scary as I suspect many clients do not check the
            returned data to make sure it actually corresponds to their original
            request. I have not seen this with a single threaded client, so
            perhaps that is a clue.

            I will try to do some more testing and see if I can provide any more
            details.

            thanks,
            Philip
            _______________________________________________
            webservices mailing list

            webservices<at>iris.washington.edu
            http://www.iris.washington.edu/mailman/listinfo/webservices





            --------------------------------------
            Bruce R Weertman
            Software Engineer
            IRIS DMC
            1408 NE 45h St, Suite 201
            Seattle, WA 98105

            bruce<at>iris.washington.edu
            (206) 547-0393


            _______________________________________________
            webservices mailing list
            webservices<at>iris.washington.edu
            http://www.iris.washington.edu/mailman/listinfo/webservices



            • For the record: This conversation drifted off-list, currently other areas are being investigated to explain the observations.

              After code review and testing there is no indication that dataselect returned wrong data to the client. Obviously we're keenly interested to know if anyone else observes this in the future.

              Chad

              On Jul 19, 2012, at 11:17 AM, Philip Crotwell wrote:

              Hi

              I don't think I can tell if it was a collision or not. All I know is
              that one request in one thread got data for a different station. It is
              true that another thread on my end asked for data from that other
              station at a similar time, but I am not sure if it was actually
              coincidental or not. Because I was doing a test using many threads on
              my end (and hence many http connections), I assumed that it was caused
              by that, but I actually don't know. Given I can't seem to reproduce
              it, I am not sure what to say.

              I am leaving the "is the answer from the same station as the request"
              check in my code, so hopefully I will notice if it happens again.

              Debugging stuff that you can't reproduce is somewhere between really,
              really hard and impossible!

              thanks,
              Philip


              On Thu, Jul 19, 2012 at 1:53 PM, Bruce Weertman
              <bruce<at>iris.washington.edu> wrote:
              Philip:

              Just to get back to you - and everybody else on the list.

              Are you saying is thread-1 and thread-2 are each making requests, but
              thread-1 gets the data that thread-2 made.

              Or something along that line?

              Possibilities:

              (1) Collision of token values. Token is generated from the request via a
              standard hashing algorithm.

              (2) In the java servlet one request gets confused with another request. This
              could happen if there was a mistake
              where the wrong scope was used for variables. For example improperly using
              variables from the servlet instance and not off
              of the stack or accidentally using a global (ie static) variable. Code
              review looks OK. But that's just code review.

              (3) Some sort of weird networking issue related to reusing http
              connections??

              I wrote a script to scan the cache (had 34,000 items in it) looking for a
              mis-match between the data and the requests,
              but I didn't find any. A necessary but not sufficient test of the cache
              working properly.


              Are you saying that you saw these requests collide
              http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
              http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

              I don't see that:

              geodude:tmp bruce$ wget -O aru.dat
              "http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
              --2012-07-19 10:19:45--
              http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
              Resolving www.iris.edu... 128.95.166.129
              Connecting to www.iris.edu|128.95.166.129|:80... connected.
              HTTP request sent, awaiting response... 200 OK
              Length: 28672 (28K) [application/vnd.fdsn.mseed]
              Saving to: `aru.dat'

              100%[==================================================================================================================================================================>]
              28,672 --.-K/s in 0.002s

              2012-07-19 10:19:45 (11.3 MB/s) - `aru.dat' saved [28672/28672]

              geodude:tmp bruce$ msi aru.dat
              II_ARU_00_BHZ, 000001, M, 4096, 2894 samples, 19.99993515 Hz,
              2009,136,01:08:44.015300
              II_ARU_00_BHZ, 000000, M, 4096, 3104 samples, 19.99993515 Hz,
              2009,136,01:11:08.715900
              II_ARU_00_BHZ, 000000, M, 4096, 3446 samples, 19.99993515 Hz,
              2009,136,01:13:43.916400
              II_ARU_00_BHZ, 000000, M, 4096, 3520 samples, 19.99993515 Hz,
              2009,136,01:16:36.217000
              II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz,
              2009,136,01:19:32.217500
              II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz,
              2009,136,01:22:37.818100
              II_ARU_00_BHZ, 000001, M, 4096, 852 samples, 19.99993515 Hz,
              2009,136,01:25:43.418700


              geodude:tmp bruce$ wget -O borg.dat
              "http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
              --2012-07-19 10:18:51--
              http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
              Resolving www.iris.edu... 128.95.166.129
              Connecting to www.iris.edu|128.95.166.129|:80... connected.
              HTTP request sent, awaiting response... 200 OK
              Length: 45056 (44K) [application/vnd.fdsn.mseed]
              Saving to: `borg.dat'

              100%[==================================================================================================================================================================>]
              45,056 --.-K/s in 0.004s

              geodude:tmp bruce$ msi borg.dat
              II_BORG_00_BHZ, 000001, M, 4096, 762 samples, 20 Hz,
              2009,136,01:08:44.049900
              II_BORG_00_BHZ, 000000, M, 4096, 2204 samples, 20 Hz,
              2009,136,01:09:22.149900
              II_BORG_00_BHZ, 000000, M, 4096, 2120 samples, 20 Hz,
              2009,136,01:11:12.349900
              II_BORG_00_BHZ, 000000, M, 4096, 2024 samples, 20 Hz,
              2009,136,01:12:58.349900
              II_BORG_00_BHZ, 000000, M, 4096, 2170 samples, 20 Hz,
              2009,136,01:14:39.549900
              II_BORG_00_BHZ, 000000, M, 4096, 2122 samples, 20 Hz,
              2009,136,01:16:28.049900
              II_BORG_00_BHZ, 000000, M, 4096, 2100 samples, 20 Hz,
              2009,136,01:18:14.149900
              II_BORG_00_BHZ, 000000, M, 4096, 2142 samples, 20 Hz,
              2009,136,01:19:59.149900
              II_BORG_00_BHZ, 000000, M, 4096, 2172 samples, 20 Hz,
              2009,136,01:21:46.249900
              II_BORG_00_BHZ, 000000, M, 4096, 2138 samples, 20 Hz,
              2009,136,01:23:34.849900
              II_BORG_00_BHZ, 000001, M, 4096, 1286 samples, 20 Hz,
              2009,136,01:25:21.749900

              Any more information would be appreciated.

              Thanks,
              -Bruce


              Begin forwarded message:



              On 2012/07/16 22:29, Philip Crotwell wrote:

              Hi

              I have been doing some tests with the dataselect web service from a
              multithreaded client (SOD) and found that occasionally I would get
              data records back in one thread that were not the channel asked for.
              Luckily I had a check in place from some earlier issues that compared
              the channel codes in the request with those in the result. Here is an
              example. It appears that the thread that requested data from BORG got
              data from ARU.


              2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
              match channelid in request.
              req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
              seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

              The request, if it helps, was
              net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

              This is a bit scary as I suspect many clients do not check the
              returned data to make sure it actually corresponds to their original
              request. I have not seen this with a single threaded client, so
              perhaps that is a clue.

              I will try to do some more testing and see if I can provide any more
              details.

              thanks,
              Philip
              _______________________________________________
              webservices mailing list

              webservices<at>iris.washington.edu
              http://www.iris.washington.edu/mailman/listinfo/webservices





              --------------------------------------
              Bruce R Weertman
              Software Engineer
              IRIS DMC
              1408 NE 45h St, Suite 201
              Seattle, WA 98105

              bruce<at>iris.washington.edu
              (206) 547-0393


              _______________________________________________
              webservices mailing list
              webservices<at>iris.washington.edu
              http://www.iris.washington.edu/mailman/listinfo/webservices

              _______________________________________________
              webservices mailing list
              webservices<at>iris.washington.edu
              http://www.iris.washington.edu/mailman/listinfo/webservices



              • Hi

                Following up on the follow up. I believe this was a client side bug in
                my seisFile library. Should be fixed now and I have put out a new
                version (1.5.2) here:
                http://code.google.com/p/seisfile/

                Thanks to all at IRIS for helping track this down.
                Philip

                On Fri, Jul 20, 2012 at 1:18 PM, Chad Trabant <chad<at>iris.washington.edu> wrote:

                For the record: This conversation drifted off-list, currently other areas are being investigated to explain the observations.

                After code review and testing there is no indication that dataselect returned wrong data to the client. Obviously we're keenly interested to know if anyone else observes this in the future.

                Chad

                On Jul 19, 2012, at 11:17 AM, Philip Crotwell wrote:

                Hi

                I don't think I can tell if it was a collision or not. All I know is
                that one request in one thread got data for a different station. It is
                true that another thread on my end asked for data from that other
                station at a similar time, but I am not sure if it was actually
                coincidental or not. Because I was doing a test using many threads on
                my end (and hence many http connections), I assumed that it was caused
                by that, but I actually don't know. Given I can't seem to reproduce
                it, I am not sure what to say.

                I am leaving the "is the answer from the same station as the request"
                check in my code, so hopefully I will notice if it happens again.

                Debugging stuff that you can't reproduce is somewhere between really,
                really hard and impossible!

                thanks,
                Philip


                On Thu, Jul 19, 2012 at 1:53 PM, Bruce Weertman
                <bruce<at>iris.washington.edu> wrote:
                Philip:

                Just to get back to you - and everybody else on the list.

                Are you saying is thread-1 and thread-2 are each making requests, but
                thread-1 gets the data that thread-2 made.

                Or something along that line?

                Possibilities:

                (1) Collision of token values. Token is generated from the request via a
                standard hashing algorithm.

                (2) In the java servlet one request gets confused with another request. This
                could happen if there was a mistake
                where the wrong scope was used for variables. For example improperly using
                variables from the servlet instance and not off
                of the stack or accidentally using a global (ie static) variable. Code
                review looks OK. But that's just code review.

                (3) Some sort of weird networking issue related to reusing http
                connections??

                I wrote a script to scan the cache (had 34,000 items in it) looking for a
                mis-match between the data and the requests,
                but I didn't find any. A necessary but not sufficient test of the cache
                working properly.


                Are you saying that you saw these requests collide
                http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
                http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

                I don't see that:

                geodude:tmp bruce$ wget -O aru.dat
                "http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
                --2012-07-19 10:19:45--
                http://www.iris.edu/ws/dataselect/query?net=II&sta=ARU&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
                Resolving www.iris.edu... 128.95.166.129
                Connecting to www.iris.edu|128.95.166.129|:80... connected.
                HTTP request sent, awaiting response... 200 OK
                Length: 28672 (28K) [application/vnd.fdsn.mseed]
                Saving to: `aru.dat'

                100%[==================================================================================================================================================================>]
                28,672 --.-K/s in 0.002s

                2012-07-19 10:19:45 (11.3 MB/s) - `aru.dat' saved [28672/28672]

                geodude:tmp bruce$ msi aru.dat
                II_ARU_00_BHZ, 000001, M, 4096, 2894 samples, 19.99993515 Hz,
                2009,136,01:08:44.015300
                II_ARU_00_BHZ, 000000, M, 4096, 3104 samples, 19.99993515 Hz,
                2009,136,01:11:08.715900
                II_ARU_00_BHZ, 000000, M, 4096, 3446 samples, 19.99993515 Hz,
                2009,136,01:13:43.916400
                II_ARU_00_BHZ, 000000, M, 4096, 3520 samples, 19.99993515 Hz,
                2009,136,01:16:36.217000
                II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz,
                2009,136,01:19:32.217500
                II_ARU_00_BHZ, 000000, M, 4096, 3712 samples, 19.99993515 Hz,
                2009,136,01:22:37.818100
                II_ARU_00_BHZ, 000001, M, 4096, 852 samples, 19.99993515 Hz,
                2009,136,01:25:43.418700


                geodude:tmp bruce$ wget -O borg.dat
                "http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26"
                --2012-07-19 10:18:51--
                http://www.iris.edu/ws/dataselect/query?net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26
                Resolving www.iris.edu... 128.95.166.129
                Connecting to www.iris.edu|128.95.166.129|:80... connected.
                HTTP request sent, awaiting response... 200 OK
                Length: 45056 (44K) [application/vnd.fdsn.mseed]
                Saving to: `borg.dat'

                100%[==================================================================================================================================================================>]
                45,056 --.-K/s in 0.004s

                geodude:tmp bruce$ msi borg.dat
                II_BORG_00_BHZ, 000001, M, 4096, 762 samples, 20 Hz,
                2009,136,01:08:44.049900
                II_BORG_00_BHZ, 000000, M, 4096, 2204 samples, 20 Hz,
                2009,136,01:09:22.149900
                II_BORG_00_BHZ, 000000, M, 4096, 2120 samples, 20 Hz,
                2009,136,01:11:12.349900
                II_BORG_00_BHZ, 000000, M, 4096, 2024 samples, 20 Hz,
                2009,136,01:12:58.349900
                II_BORG_00_BHZ, 000000, M, 4096, 2170 samples, 20 Hz,
                2009,136,01:14:39.549900
                II_BORG_00_BHZ, 000000, M, 4096, 2122 samples, 20 Hz,
                2009,136,01:16:28.049900
                II_BORG_00_BHZ, 000000, M, 4096, 2100 samples, 20 Hz,
                2009,136,01:18:14.149900
                II_BORG_00_BHZ, 000000, M, 4096, 2142 samples, 20 Hz,
                2009,136,01:19:59.149900
                II_BORG_00_BHZ, 000000, M, 4096, 2172 samples, 20 Hz,
                2009,136,01:21:46.249900
                II_BORG_00_BHZ, 000000, M, 4096, 2138 samples, 20 Hz,
                2009,136,01:23:34.849900
                II_BORG_00_BHZ, 000001, M, 4096, 1286 samples, 20 Hz,
                2009,136,01:25:21.749900

                Any more information would be appreciated.

                Thanks,
                -Bruce


                Begin forwarded message:



                On 2012/07/16 22:29, Philip Crotwell wrote:

                Hi

                I have been doing some tests with the dataselect web service from a
                multithreaded client (SOD) and found that occasionally I would get
                data records back in one thread that were not the channel asked for.
                Luckily I had a check in place from some earlier issues that compared
                the channel codes in the request with those in the result. Here is an
                example. It appears that the thread that requested data from BORG got
                data from ARU.


                2012-07-16 15:51:26,794 - Channel id in returned seismogram doesn not
                match channelid in request.
                req=II.1986-01-01T00:00:00.000GMT.BORG.00.BHZ.2003-08-29T00:00:00.000GMT
                seis=II.1986-01-01T00:00:00.000GMT.ARU.00.BHZ.2003-08-29T00:00:00.000GMT

                The request, if it helps, was
                net=II&sta=BORG&loc=00&cha=BHZ&start=2009-05-16T01:08:44&end=2009-05-16T01:26:26

                This is a bit scary as I suspect many clients do not check the
                returned data to make sure it actually corresponds to their original
                request. I have not seen this with a single threaded client, so
                perhaps that is a clue.

                I will try to do some more testing and see if I can provide any more
                details.

                thanks,
                Philip
                _______________________________________________
                webservices mailing list

                webservices<at>iris.washington.edu
                http://www.iris.washington.edu/mailman/listinfo/webservices





                --------------------------------------
                Bruce R Weertman
                Software Engineer
                IRIS DMC
                1408 NE 45h St, Suite 201
                Seattle, WA 98105

                bruce<at>iris.washington.edu
                (206) 547-0393


                _______________________________________________
                webservices mailing list
                webservices<at>iris.washington.edu
                http://www.iris.washington.edu/mailman/listinfo/webservices

                _______________________________________________
                webservices mailing list
                webservices<at>iris.washington.edu
                http://www.iris.washington.edu/mailman/listinfo/webservices


                _______________________________________________
                webservices mailing list
                webservices<at>iris.washington.edu
                http://www.iris.washington.edu/mailman/listinfo/webservices

10:05:52 v.01697673