Re: svn commit: r887916 - /ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java

[David E. Jones-2]

Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.

-David


On Dec 7, 2009, at 7:00 AM, [hidden email] wrote:

> Author: jleroux
> Date: Mon Dec  7 13:00:09 2009
> New Revision: 887916
>
> URL: http://svn.apache.org/viewvc?rev=887916&view=rev
> Log:
> A patch from Adrian Crum "ServerHit aborts transactions when trying to create entries with duplicate startTime(s)." (https://issues.apache.org/jira/browse/OFBIZ-2208) - OFBIZ-2208
> This add synchronization for ServerHit entities creation. Hence startTime is no longer used.
> I have also removed some comment about the problem, and added one for startTime no longer used.
>
> Note: If synchronization proves to slow down sites we could introduce a properties in serverstats.properties to switch from using it or not since I did not remove startTime from the method signature
> Then we will use one or the other lines
> -            serverHit.set("hitStartDateTime", new java.sql.Timestamp(startTime));
> +            serverHit.set("hitStartDateTime", getNowTimestamp());
>
> Modified:
>    ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
>
> Modified: ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
> URL: http://svn.apache.org/viewvc/ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java?rev=887916&r1=887915&r2=887916&view=diff
> ==============================================================================
> --- ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java (original)
> +++ ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java Mon Dec  7 13:00:09 2009
> @@ -618,7 +618,7 @@
>             GenericValue serverHit = delegator.makeValue("ServerHit");
>
>             serverHit.set("visitId", visitId);
> -            serverHit.set("hitStartDateTime", new java.sql.Timestamp(startTime));
> +            serverHit.set("hitStartDateTime", getNowTimestamp()); // A change was introduced with https://issues.apache.org/jira/browse/OFBIZ-2208. Since then startTime is not used anymore
>             serverHit.set("hitTypeId", ServerHitBin.typeIds[this.type]);
>             if (userLogin != null) {
>                 serverHit.set("userLoginId", userLogin.get("userLoginId"));
> @@ -651,27 +651,15 @@
>                 Debug.logError("Unable to get localhost internet address: " + e.toString(), module);
>             }
>
> -            // The problem with
> -            //
> -            //     serverHit.create();
> -            //
> -            // is that if there are two requests with the same startTime (this should only happen with MySQL see https://issues.apache.org/jira/browse/OFBIZ-2208)
> -            // then this will go wrong and abort the actual
> -            // transaction we are interested in.
> -            // Another way instead of using create is to store or update,
> -            // that is overwrite in case there already was an entry, thus
> -            // avoiding the transaction being aborted which is not
> -            // less desirable than having multiple requests with the
> -            // same startTime overwriting each other.
> -            // This may not satisfy those who want to record each and
> -            // every server hit even with equal startTimes but that could be
> -            // solved adding a counter to the ServerHit's PK (a counter
> -            // counting multiple hits at the same startTime).
>             try {
>                 serverHit.create();
>             } catch (GenericEntityException e) {
> -                Debug.logError(e, "Could not save ServerHit:", module);
> +                Debug.logError(e, "Could not save ServerHit: ", module);
>             }
>         }
>     }
> +    
> +    public synchronized java.sql.Timestamp getNowTimestamp() {
> +        return new java.sql.Timestamp(System.currentTimeMillis());
> +    }
> }
>
>

[Jacques Le Roux]

Ha yes!

It's only better for a sile OFBiz instance :/ (and we have still not feedback on performances)
What would you suggest ? If I remember well Karim's solution was good but without  an upgrade path...

Jacques
()  ascii ribbon campaign against HTML e-mail
/\  www.asciiribbon.org

From: "David E Jones" <[hidden email]>

>
> Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.
>
> -David
>
>
> On Dec 7, 2009, at 7:00 AM, [hidden email] wrote:
>
>> Author: jleroux
>> Date: Mon Dec  7 13:00:09 2009
>> New Revision: 887916
>>
>> URL: http://svn.apache.org/viewvc?rev=887916&view=rev
>> Log:
>> A patch from Adrian Crum "ServerHit aborts transactions when trying to create entries with duplicate startTime(s)."
>> (https://issues.apache.org/jira/browse/OFBIZ-2208) - OFBIZ-2208
>> This add synchronization for ServerHit entities creation. Hence startTime is no longer used.
>> I have also removed some comment about the problem, and added one for startTime no longer used.
>>
>> Note: If synchronization proves to slow down sites we could introduce a properties in serverstats.properties to switch from using
>> it or not since I did not remove startTime from the method signature
>> Then we will use one or the other lines
>> -            serverHit.set("hitStartDateTime", new java.sql.Timestamp(startTime));
>> +            serverHit.set("hitStartDateTime", getNowTimestamp());
>>
>> Modified:
>>    ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
>>
>> Modified: ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
>> URL:
>> http://svn.apache.org/viewvc/ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java?rev=887916&r1=887915&r2=887916&view=diff
>> ==============================================================================
>> --- ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java (original)
>> +++ ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java Mon Dec  7 13:00:09 2009
>> @@ -618,7 +618,7 @@
>>             GenericValue serverHit = delegator.makeValue("ServerHit");
>>
>>             serverHit.set("visitId", visitId);
>> -            serverHit.set("hitStartDateTime", new java.sql.Timestamp(startTime));
>> +            serverHit.set("hitStartDateTime", getNowTimestamp()); // A change was introduced with
>> https://issues.apache.org/jira/browse/OFBIZ-2208. Since then startTime is not used anymore
>>             serverHit.set("hitTypeId", ServerHitBin.typeIds[this.type]);
>>             if (userLogin != null) {
>>                 serverHit.set("userLoginId", userLogin.get("userLoginId"));
>> @@ -651,27 +651,15 @@
>>                 Debug.logError("Unable to get localhost internet address: " + e.toString(), module);
>>             }
>>
>> -            // The problem with
>> -            //
>> -            //     serverHit.create();
>> -            //
>> -            // is that if there are two requests with the same startTime (this should only happen with MySQL see
>> https://issues.apache.org/jira/browse/OFBIZ-2208)
>> -            // then this will go wrong and abort the actual
>> -            // transaction we are interested in.
>> -            // Another way instead of using create is to store or update,
>> -            // that is overwrite in case there already was an entry, thus
>> -            // avoiding the transaction being aborted which is not
>> -            // less desirable than having multiple requests with the
>> -            // same startTime overwriting each other.
>> -            // This may not satisfy those who want to record each and
>> -            // every server hit even with equal startTimes but that could be
>> -            // solved adding a counter to the ServerHit's PK (a counter
>> -            // counting multiple hits at the same startTime).
>>             try {
>>                 serverHit.create();
>>             } catch (GenericEntityException e) {
>> -                Debug.logError(e, "Could not save ServerHit:", module);
>> +                Debug.logError(e, "Could not save ServerHit: ", module);
>>             }
>>         }
>>     }
>> +
>> +    public synchronized java.sql.Timestamp getNowTimestamp() {
>> +        return new java.sql.Timestamp(System.currentTimeMillis());
>> +    }
>> }
>>
>>
>

[Adrian Crum]

Jacques,

Anyone wanting to have detailed records of every server hit will have to
expect it to affect performance. You can't track server hits for free.

If performance becomes a problem, there is another way to do
synchronization that would be a little faster.

-Adrian

Jacques Le Roux wrote:

> Ha yes!
>
> It's only better for a sile OFBiz instance :/ (and we have still not
> feedback on performances)
> What would you suggest ? If I remember well Karim's solution was good
> but without  an upgrade path...
>
> Jacques
> ()  ascii ribbon campaign against HTML e-mail
> /\  www.asciiribbon.org
>
> From: "David E Jones" <[hidden email]>
>>
>> Just a quick thing I noticed while looking at this again: this won't
>> prevent conflicts in multi-server deployments.
>>
>> -David
>>
>>
>> On Dec 7, 2009, at 7:00 AM, [hidden email] wrote:
>>
>>> Author: jleroux
>>> Date: Mon Dec  7 13:00:09 2009
>>> New Revision: 887916
>>>
>>> URL: http://svn.apache.org/viewvc?rev=887916&view=rev
>>> Log:
>>> A patch from Adrian Crum "ServerHit aborts transactions when trying
>>> to create entries with duplicate startTime(s)."
>>> (https://issues.apache.org/jira/browse/OFBIZ-2208) - OFBIZ-2208
>>> This add synchronization for ServerHit entities creation. Hence
>>> startTime is no longer used.
>>> I have also removed some comment about the problem, and added one for
>>> startTime no longer used.
>>>
>>> Note: If synchronization proves to slow down sites we could introduce
>>> a properties in serverstats.properties to switch from using it or not
>>> since I did not remove startTime from the method signature
>>> Then we will use one or the other lines
>>> -            serverHit.set("hitStartDateTime", new
>>> java.sql.Timestamp(startTime));
>>> +            serverHit.set("hitStartDateTime", getNowTimestamp());
>>>
>>> Modified:
>>>    
>>> ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
>>>
>>>
>>> Modified:
>>> ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
>>>
>>> URL:
>>> http://svn.apache.org/viewvc/ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java?rev=887916&r1=887915&r2=887916&view=diff 
>>>
>>> ==============================================================================
>>>
>>> ---
>>> ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
>>> (original)
>>> +++
>>> ofbiz/trunk/framework/webapp/src/org/ofbiz/webapp/stats/ServerHitBin.java
>>> Mon Dec  7 13:00:09 2009
>>> @@ -618,7 +618,7 @@
>>>             GenericValue serverHit = delegator.makeValue("ServerHit");
>>>
>>>             serverHit.set("visitId", visitId);
>>> -            serverHit.set("hitStartDateTime", new
>>> java.sql.Timestamp(startTime));
>>> +            serverHit.set("hitStartDateTime", getNowTimestamp()); //
>>> A change was introduced with
>>> https://issues.apache.org/jira/browse/OFBIZ-2208. Since then
>>> startTime is not used anymore
>>>             serverHit.set("hitTypeId", ServerHitBin.typeIds[this.type]);
>>>             if (userLogin != null) {
>>>                 serverHit.set("userLoginId",
>>> userLogin.get("userLoginId"));
>>> @@ -651,27 +651,15 @@
>>>                 Debug.logError("Unable to get localhost internet
>>> address: " + e.toString(), module);
>>>             }
>>>
>>> -            // The problem with
>>> -            //
>>> -            //     serverHit.create();
>>> -            //
>>> -            // is that if there are two requests with the same
>>> startTime (this should only happen with MySQL see
>>> https://issues.apache.org/jira/browse/OFBIZ-2208)
>>> -            // then this will go wrong and abort the actual
>>> -            // transaction we are interested in.
>>> -            // Another way instead of using create is to store or
>>> update,
>>> -            // that is overwrite in case there already was an entry,
>>> thus
>>> -            // avoiding the transaction being aborted which is not
>>> -            // less desirable than having multiple requests with the
>>> -            // same startTime overwriting each other.
>>> -            // This may not satisfy those who want to record each and
>>> -            // every server hit even with equal startTimes but that
>>> could be
>>> -            // solved adding a counter to the ServerHit's PK (a counter
>>> -            // counting multiple hits at the same startTime).
>>>             try {
>>>                 serverHit.create();
>>>             } catch (GenericEntityException e) {
>>> -                Debug.logError(e, "Could not save ServerHit:", module);
>>> +                Debug.logError(e, "Could not save ServerHit: ",
>>> module);
>>>             }
>>>         }
>>>     }
>>> +
>>> +    public synchronized java.sql.Timestamp getNowTimestamp() {
>>> +        return new java.sql.Timestamp(System.currentTimeMillis());
>>> +    }
>>> }
>>>
>>>
>>
>
>
>

[Adam Heath-2]

David E Jones wrote:
> Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.
>
> -David

This patch is completely, 100% wrong, and won't fix the problem.


install ofbiz, install demo data, run it.

/usr/sbin/ab -c30 -t 50 http://localhost:8080/webtools/control/main

It has absolutely nothing to do with any database, nothing to do with
synchronization.  The faster your computer that is running ofbiz, the
faster it can respond to requests, and the easier it becomes to hit
this bug.

[Adrian Crum]

Have you visited the related Jira issue?

I can repeat the problem with my local machine, and the patch does
indeed fix it.

I agree it doesn't solve the multi-server issue. I don't know why the
original idea of a sequence ID wasn't used.

-Adrian

Adam Heath wrote:

> David E Jones wrote:
>> Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.
>>
>> -David
>
> This patch is completely, 100% wrong, and won't fix the problem.
>
>
> install ofbiz, install demo data, run it.
>
> /usr/sbin/ab -c30 -t 50 http://localhost:8080/webtools/control/main
>
> It has absolutely nothing to do with any database, nothing to do with
> synchronization.  The faster your computer that is running ofbiz, the
> faster it can respond to requests, and the easier it becomes to hit
> this bug.
>
>

[David E. Jones-2]

On Dec 7, 2009, at 1:37 PM, Adam Heath wrote:

> David E Jones wrote:
>> Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.
>>
>> -David
>
> This patch is completely, 100% wrong, and won't fix the problem.
>
>
> install ofbiz, install demo data, run it.
>
> /usr/sbin/ab -c30 -t 50 http://localhost:8080/webtools/control/main
>
> It has absolutely nothing to do with any database, nothing to do with
> synchronization.  The faster your computer that is running ofbiz, the
> faster it can respond to requests, and the easier it becomes to hit
> this bug.

You're right. Just because it's synchronized doesn't mean that you won't get multiple calls within a millisecond.

I guess we have two options:

1. query to check for a conflict and add 1ms if there is a conflict
2. change the entity to use a sequenced ID as the pk instead of the timestamp

-David

[Adam Heath-2]

David E Jones wrote:

> On Dec 7, 2009, at 1:37 PM, Adam Heath wrote:
>
>> David E Jones wrote:
>>> Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.
>>>
>>> -David
>> This patch is completely, 100% wrong, and won't fix the problem.
>>
>>
>> install ofbiz, install demo data, run it.
>>
>> /usr/sbin/ab -c30 -t 50 http://localhost:8080/webtools/control/main
>>
>> It has absolutely nothing to do with any database, nothing to do with
>> synchronization.  The faster your computer that is running ofbiz, the
>> faster it can respond to requests, and the easier it becomes to hit
>> this bug.
>
> You're right. Just because it's synchronized doesn't mean that you won't get multiple calls within a millisecond.
>
> I guess we have two options:
>
> 1. query to check for a conflict and add 1ms if there is a conflict

This still won't fix it, for the exact same reason.  There are even
more requests coming in, for the next millisecond.  The fix here is
have something else completely be the key, or have something more be
part of the key.

> 2. change the entity to use a sequenced ID as the pk instead of the timestamp

With possibly a larger allocation window.

[Jacques Le Roux]

From: "Adrian Crum" <[hidden email]>
> Have you visited the related Jira issue?
>
> I can repeat the problem with my local machine, and the patch does
> indeed fix it.
>
> I agree it doesn't solve the multi-server issue. I don't know why the
> original idea of a sequence ID wasn't used.

Because no update path (change in Entity) was provided

Jacques
()  ascii ribbon campaign against HTML e-mail
/\  www.asciiribbon.org

> -Adrian
>
> Adam Heath wrote:
>> David E Jones wrote:
>>> Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.
>>>
>>> -David
>>
>> This patch is completely, 100% wrong, and won't fix the problem.
>>
>>
>> install ofbiz, install demo data, run it.
>>
>> /usr/sbin/ab -c30 -t 50 http://localhost:8080/webtools/control/main
>>
>> It has absolutely nothing to do with any database, nothing to do with
>> synchronization.  The faster your computer that is running ofbiz, the
>> faster it can respond to requests, and the easier it becomes to hit
>> this bug.
>>
>>
>

[Jacques Le Roux]

Reverted at r888111 in trunk, R9.04 at r888113

Jacques
()  ascii ribbon campaign against HTML e-mail
/\  www.asciiribbon.org

From: "Adam Heath" <[hidden email]>

> David E Jones wrote:
>> Just a quick thing I noticed while looking at this again: this won't prevent conflicts in multi-server deployments.
>>
>> -David
>
> This patch is completely, 100% wrong, and won't fix the problem.
>
>
> install ofbiz, install demo data, run it.
>
> /usr/sbin/ab -c30 -t 50 http://localhost:8080/webtools/control/main
>
> It has absolutely nothing to do with any database, nothing to do with
> synchronization.  The faster your computer that is running ofbiz, the
> faster it can respond to requests, and the easier it becomes to hit
> this bug.
>

[Adam Heath-2]

Jacques Le Roux wrote:
> Reverted at r888111 in trunk, R9.04 at r888113

Actually, there's more to this.

If you are *just* using ControlServlet parts of ofbiz, which does
serverhit stuff, then you will probably never ever hit this bug.

However, when using webslinger, which is a faster rendering
technology, the bug happens very quick.

Something has happened recently in ofbiz, that is very bad for
performance.  I'm seeing a call to getUserPreferenceGroup service in
webtools control/main being called.  This service seems to always take
more than 100 milliseconds, so this means this bug is never hit.  But
the bug is still there.

Ofbiz backend pages are not optimized for high-volume sites.  Sessions
*must* only be created when nescessary, only after a user has logged
in, or after someone is actually required to be displayed.  Just
visiting the main page should not create a session.  Also, pages
should not always be displayed with https, unless required.  The
overhead for encryption can then be saved.  Logging must not only be
turned down, but *removed* from hot-paths, period.  I'd even go so far
as to have 2 different versions of ofbiz compiled, using byte-code
manipulation to remove log calls.

[Adam Heath-2]

Adam Heath wrote:

> Jacques Le Roux wrote:
>> Reverted at r888111 in trunk, R9.04 at r888113
>
> Actually, there's more to this.
>
> If you are *just* using ControlServlet parts of ofbiz, which does
> serverhit stuff, then you will probably never ever hit this bug.
>
> However, when using webslinger, which is a faster rendering
> technology, the bug happens very quick.
>
> Something has happened recently in ofbiz, that is very bad for
> performance.  I'm seeing a call to getUserPreferenceGroup service in
> webtools control/main being called.  This service seems to always take
> more than 100 milliseconds, so this means this bug is never hit.  But
> the bug is still there.
>
> Ofbiz backend pages are not optimized for high-volume sites.  Sessions
> *must* only be created when nescessary, only after a user has logged
> in, or after someone is actually required to be displayed.  Just
> visiting the main page should not create a session.  Also, pages
> should not always be displayed with https, unless required.  The
> overhead for encryption can then be saved.  Logging must not only be
> turned down, but *removed* from hot-paths, period.  I'd even go so far
> as to have 2 different versions of ofbiz compiled, using byte-code
> manipulation to remove log calls.

ClientAbortException/Pipe errors should not be logged.

[Jacques Le Roux]

Thanks Adam,

All this is very interesting. I never tried webslinger, because I don't know how to use it and did not get a chance to dig in code
to understand

Jacques
()  ascii ribbon campaign against HTML e-mail
/\  www.asciiribbon.org


From: "Adam Heath" <[hidden email]>

> Adam Heath wrote:
>> Jacques Le Roux wrote:
>>> Reverted at r888111 in trunk, R9.04 at r888113
>>
>> Actually, there's more to this.
>>
>> If you are *just* using ControlServlet parts of ofbiz, which does
>> serverhit stuff, then you will probably never ever hit this bug.
>>
>> However, when using webslinger, which is a faster rendering
>> technology, the bug happens very quick.
>>
>> Something has happened recently in ofbiz, that is very bad for
>> performance.  I'm seeing a call to getUserPreferenceGroup service in
>> webtools control/main being called.  This service seems to always take
>> more than 100 milliseconds, so this means this bug is never hit.  But
>> the bug is still there.
>>
>> Ofbiz backend pages are not optimized for high-volume sites.  Sessions
>> *must* only be created when nescessary, only after a user has logged
>> in, or after someone is actually required to be displayed.  Just
>> visiting the main page should not create a session.  Also, pages
>> should not always be displayed with https, unless required.  The
>> overhead for encryption can then be saved.  Logging must not only be
>> turned down, but *removed* from hot-paths, period.  I'd even go so far
>> as to have 2 different versions of ofbiz compiled, using byte-code
>> manipulation to remove log calls.
>
> ClientAbortException/Pipe errors should not be logged.
>

[David E. Jones-2]

On Dec 7, 2009, at 2:36 PM, Adam Heath wrote:

> Jacques Le Roux wrote:
>> Reverted at r888111 in trunk, R9.04 at r888113
>
> Actually, there's more to this.
>
> If you are *just* using ControlServlet parts of ofbiz, which does
> serverhit stuff, then you will probably never ever hit this bug.
>
> However, when using webslinger, which is a faster rendering
> technology, the bug happens very quick.
>
> Something has happened recently in ofbiz, that is very bad for
> performance.  I'm seeing a call to getUserPreferenceGroup service in
> webtools control/main being called.  This service seems to always take
> more than 100 milliseconds, so this means this bug is never hit.  But
> the bug is still there.

The user preference stuff is definitely a prime candidate for caching (high read to write ratio).

-David