exist-development

[Exist-development] Very weird and serious error in trunk!

[Andrzej J. T. <an...@ch...>]

Wolfgang:

I've hit a very weird error in trunk, that could potentially be very serious.

I have some code in a module that looks like this:

declare function common:test()
{
    let $line := <property name="java.naming.security.credentials"
			   value="{ util:binary-to-string( xs:base64Binary( 'dGVzdAoK' ) ) }"/>

    let $debug2 := util:log-system-out( concat( "Credentials XML: ",
			util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )

    return $line
};

declare function common:get-ldap-connection()  as xs:integer
{		
    let $test := common:test()

    let $contextProps :=
    <properties>
       <property name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>
       <property name="java.naming.provider.url"
		 value="{ common:get-config()/config/ldap/url/text() }"/>
       <property name="java.naming.security.authentication" value="simple"/>
       <property name="java.naming.security.principal"
		 value="{ common:get-config()/config/ldap/adminUser/text() }"/>
       <property name="java.naming.security.credentials"
		 value="{ util:binary-to-string( xs:base64Binary(
				common:get-config()/config/ldap/adminPswd/text() ) ) }"/>
    </properties>

    let $ctx := jndi:get-dir-context( $contextProps )
	
    return $ctx
};

I then have a xquery that includes this module, and does something like this:

	let $cnx := common:get-ldap-connection()

All works fine if I call this from the sandbox and in the console log I will see the following line
produced by the common:test() function:

(Line: 494) Credentials XML: <property name="java.naming.security.credentials"
                                       value="test&#xA;&#xA;"/>


The problem I run into is that when I run this xquery from the scheduler (which is how it's intended
to run...it's a batch reporting job), cause then I get the following output in the console log:

(Line: 494) Credentials XML: <property name="java.naming.security.credentials" value="test&#xA;&#xA;
test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA;
test&#xA;&#xA;"/>

I get 8 concatenated decoded values in the value attribute!!!!

This should never happen!!!!  Of course, in that situation, I fail to get an LDAP connection since
the password (the credentials) is a concatenation of 8 copies of the actual password, and so fails,
if I remove the call to the test function.  If I leave in the call to the test function, then the
correct (non-replicated) password is inserted into the credentials element of the $contextProps
variable. If I remove the test function call, then I get the same replication in $contextProps.

What is weird is that the error only shows in the one place and is sensitive to order. If I put the
call to the test function after the construction of the $contextProps value, then $contextProps gets
the repeated value and the test function returns a correct, unrepeated value.

I've been trying to create a simple test case to replicate this, but have not yet been successful.
It seems I need to run the big batch job, where the included module is 3600 lines long, and the
actual xquery is very long and complex as well.

But the code snippet that causes this bug is static code in the common:test() function, and should
always return the correct result.

I'm not sure what is causing this.  Could it be the new Binary Value caching/handling under weird
conditions that only happen when running under a scheduled task?  I've never managed to reproduce
this when calling xqueries directly (the ldap connection call is made all over the place in our web
app for authentication purposes).  Maybe util:binary-to-string() is at fault, but that seems
unlikely.  Maybe some of your path wrapper stuff?

This exact same code runs just fine as a scheduled task in an older version of trunk (from late
summer last year), so it's definitely something new in trunk that has manifested since then.

Any ideas on what might cause something this strange?  I has me very worried since this is pretty
basic stuff....and thus might cause other things like DB corruption, or incorrect values being
written or wrong logic paths being followed.

I'll keep trying to create a simple test case that illustrates this, but I think it may not be
possible to do so.

Help!

Thanks!

-- 
Andrzej Taramina
Chaeron Corporation: Enterprise System Solutions
http://www.chaeron.com

Re: [Exist-development] Very weird and serious error in trunk!

[Wolfgang M. <wol...@ex...>]

Assuming that the XQuery is really as simple as this:

<property name="java.naming.security.credentials"
                          value="{ util:binary-to-string(
xs:base64Binary( 'dGVzdAoK' ) ) }"/>

I would guess that the base64Binary is cleaned up when the query runs
stand-alone, but not when it is called through the scheduler. Maybe a
missing reset on the context? If it is, it should be reproducible.

Wolfgang

Re: [Exist-development] Very weird and serious error in trunk!

[Adam R. <ad...@ex...>]

> Assuming that the XQuery is really as simple as this:
>
> <property name="java.naming.security.credentials"
>                          value="{ util:binary-to-string(
> xs:base64Binary( 'dGVzdAoK' ) ) }"/>
>
> I would guess that the base64Binary is cleaned up when the query runs
> stand-alone, but not when it is called through the scheduler. Maybe a
> missing reset on the context?

I checked, and it was indeed the case that binary resources were not
being cleaned up after execution through the Scheduler. I have fixed
that, but I am not sure it will fix the issue that Andrzej is seeing -
perhaps he could test and let us know?


-- 
Adam Retter

eXist Developer
{ United Kingdom }
ad...@ex...
irc://irc.freenode.net/existdb

Re: [Exist-development] Very weird and serious error in trunk!

[Andrzej J. T. <an...@ch...>]

Adam:

> I checked, and it was indeed the case that binary resources were not
> being cleaned up after execution through the Scheduler. I have fixed
> that, but I am not sure it will fix the issue that Andrzej is seeing -
> perhaps he could test and let us know?

I'll give it a try later today!  Fingers crossed....

Thanks for the quick response.

-- 
Andrzej Taramina
Chaeron Corporation: Enterprise System Solutions
http://www.chaeron.com

Re: [Exist-development] Very weird and serious error in trunk!

[Adam R. <ad...@ex...>]

I guess its not so serious ;-)

As its running from the scheduler, and you see the value repeat itself
8 times, could we hazard a guess that your scheduled task has been
called 8 times?

The new BinaryValues stuff,if it is not cleaned up just results in a
memory-leak, it is safely re-useable. So you can re-read the same
InputStream multiple times!

I would guess that somehow, something is appended to a session
variable, and this is not being cleaned up.

If you could remove the ldap stuff, and create some sort of
reproducible test case I would be happy to look into this.

Also for eXist-db related issues, could I ask that you use my
ad...@ex... email address. And if you have eXist Solutions
enquiries, or are one of our customers then use my
ad...@ex... email address. It helps me to keep these
things organised.

Thanks Adam.

On 30 April 2011 00:55, Andrzej Jan Taramina <an...@ch...> wrote:
> Wolfgang:
>
> I've hit a very weird error in trunk, that could potentially be very serious.
>
> I have some code in a module that looks like this:
>
> declare function common:test()
> {
>    let $line := <property name="java.naming.security.credentials"
>                           value="{ util:binary-to-string( xs:base64Binary( 'dGVzdAoK' ) ) }"/>
>
>    let $debug2 := util:log-system-out( concat( "Credentials XML: ",
>                        util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )
>
>    return $line
> };
>
> declare function common:get-ldap-connection()  as xs:integer
> {
>    let $test := common:test()
>
>    let $contextProps :=
>    <properties>
>       <property name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>
>       <property name="java.naming.provider.url"
>                 value="{ common:get-config()/config/ldap/url/text() }"/>
>       <property name="java.naming.security.authentication" value="simple"/>
>       <property name="java.naming.security.principal"
>                 value="{ common:get-config()/config/ldap/adminUser/text() }"/>
>       <property name="java.naming.security.credentials"
>                 value="{ util:binary-to-string( xs:base64Binary(
>                                common:get-config()/config/ldap/adminPswd/text() ) ) }"/>
>    </properties>
>
>    let $ctx := jndi:get-dir-context( $contextProps )
>
>    return $ctx
> };
>
> I then have a xquery that includes this module, and does something like this:
>
>        let $cnx := common:get-ldap-connection()
>
> All works fine if I call this from the sandbox and in the console log I will see the following line
> produced by the common:test() function:
>
> (Line: 494) Credentials XML: <property name="java.naming.security.credentials"
>                                       value="test&#xA;&#xA;"/>
>
>
> The problem I run into is that when I run this xquery from the scheduler (which is how it's intended
> to run...it's a batch reporting job), cause then I get the following output in the console log:
>
> (Line: 494) Credentials XML: <property name="java.naming.security.credentials" value="test&#xA;&#xA;
> test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA;
> test&#xA;&#xA;"/>
>
> I get 8 concatenated decoded values in the value attribute!!!!
>
> This should never happen!!!!  Of course, in that situation, I fail to get an LDAP connection since
> the password (the credentials) is a concatenation of 8 copies of the actual password, and so fails,
> if I remove the call to the test function.  If I leave in the call to the test function, then the
> correct (non-replicated) password is inserted into the credentials element of the $contextProps
> variable. If I remove the test function call, then I get the same replication in $contextProps.
>
> What is weird is that the error only shows in the one place and is sensitive to order. If I put the
> call to the test function after the construction of the $contextProps value, then $contextProps gets
> the repeated value and the test function returns a correct, unrepeated value.
>
> I've been trying to create a simple test case to replicate this, but have not yet been successful.
> It seems I need to run the big batch job, where the included module is 3600 lines long, and the
> actual xquery is very long and complex as well.
>
> But the code snippet that causes this bug is static code in the common:test() function, and should
> always return the correct result.
>
> I'm not sure what is causing this.  Could it be the new Binary Value caching/handling under weird
> conditions that only happen when running under a scheduled task?  I've never managed to reproduce
> this when calling xqueries directly (the ldap connection call is made all over the place in our web
> app for authentication purposes).  Maybe util:binary-to-string() is at fault, but that seems
> unlikely.  Maybe some of your path wrapper stuff?
>
> This exact same code runs just fine as a scheduled task in an older version of trunk (from late
> summer last year), so it's definitely something new in trunk that has manifested since then.
>
> Any ideas on what might cause something this strange?  I has me very worried since this is pretty
> basic stuff....and thus might cause other things like DB corruption, or incorrect values being
> written or wrong logic paths being followed.
>
> I'll keep trying to create a simple test case that illustrates this, but I think it may not be
> possible to do so.
>
> Help!
>
> Thanks!
>
> --
> Andrzej Taramina
> Chaeron Corporation: Enterprise System Solutions
> http://www.chaeron.com
>



-- 
Adam Retter
Director, eXist Solutions GmbH

e: ad...@ex...
w: http://www.existsolutions.com
t: +44 20 3239 7236
m: +44 7714 330069
Skype: adam.retter

Company Registration: HRB 89454, Amtsgericht Darmstadt

Re: [Exist-development] Very weird and serious error in trunk!

[Andrzej J. T. <an...@ch...>]

Adam:

> I guess its not so serious ;-)

It is to me. ;-)

> As its running from the scheduler, and you see the value repeat itself
> 8 times, could we hazard a guess that your scheduled task has been
> called 8 times?

Nope.  The task has only been called once.  And if I initiate the task multiple times, it still
always shows either 8 or 1 repetitions. No other combo ever appears, which is very weird.

I tried your fix....and it still does the same thing.

> The new BinaryValues stuff,if it is not cleaned up just results in a
> memory-leak, it is safely re-useable. So you can re-read the same
> InputStream multiple times!

I don't think that is the cause of the issue.

> I would guess that somehow, something is appended to a session
> variable, and this is not being cleaned up.

Not sure why that would replicate a constant value.

> If you could remove the ldap stuff, and create some sort of
> reproducible test case I would be happy to look into this.

I've been trying...and have not yet managed to replicate in a simple case. I think it's related to
the complexity of the XQuery.

Gonna try turning off the query optimizer and see if that makes any difference.

> Also for eXist-db related issues, could I ask that you use my
> ad...@ex... email address. And if you have eXist Solutions
> enquiries, or are one of our customers then use my
> ad...@ex... email address. It helps me to keep these
> things organised.

Sure thing....

....Andrzej

> Thanks Adam.
> 
> On 30 April 2011 00:55, Andrzej Jan Taramina <an...@ch...> wrote:
>> Wolfgang:
>>
>> I've hit a very weird error in trunk, that could potentially be very serious.
>>
>> I have some code in a module that looks like this:
>>
>> declare function common:test()
>> {
>>    let $line := <property name="java.naming.security.credentials"
>>                           value="{ util:binary-to-string( xs:base64Binary( 'dGVzdAoK' ) ) }"/>
>>
>>    let $debug2 := util:log-system-out( concat( "Credentials XML: ",
>>                        util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )
>>
>>    return $line
>> };
>>
>> declare function common:get-ldap-connection()  as xs:integer
>> {
>>    let $test := common:test()
>>
>>    let $contextProps :=
>>    <properties>
>>       <property name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>
>>       <property name="java.naming.provider.url"
>>                 value="{ common:get-config()/config/ldap/url/text() }"/>
>>       <property name="java.naming.security.authentication" value="simple"/>
>>       <property name="java.naming.security.principal"
>>                 value="{ common:get-config()/config/ldap/adminUser/text() }"/>
>>       <property name="java.naming.security.credentials"
>>                 value="{ util:binary-to-string( xs:base64Binary(
>>                                common:get-config()/config/ldap/adminPswd/text() ) ) }"/>
>>    </properties>
>>
>>    let $ctx := jndi:get-dir-context( $contextProps )
>>
>>    return $ctx
>> };
>>
>> I then have a xquery that includes this module, and does something like this:
>>
>>        let $cnx := common:get-ldap-connection()
>>
>> All works fine if I call this from the sandbox and in the console log I will see the following line
>> produced by the common:test() function:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials"
>>                                       value="test&#xA;&#xA;"/>
>>
>>
>> The problem I run into is that when I run this xquery from the scheduler (which is how it's intended
>> to run...it's a batch reporting job), cause then I get the following output in the console log:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials" value="test&#xA;&#xA;
>> test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA;
>> test&#xA;&#xA;"/>
>>
>> I get 8 concatenated decoded values in the value attribute!!!!
>>
>> This should never happen!!!!  Of course, in that situation, I fail to get an LDAP connection since
>> the password (the credentials) is a concatenation of 8 copies of the actual password, and so fails,
>> if I remove the call to the test function.  If I leave in the call to the test function, then the
>> correct (non-replicated) password is inserted into the credentials element of the $contextProps
>> variable. If I remove the test function call, then I get the same replication in $contextProps.
>>
>> What is weird is that the error only shows in the one place and is sensitive to order. If I put the
>> call to the test function after the construction of the $contextProps value, then $contextProps gets
>> the repeated value and the test function returns a correct, unrepeated value.
>>
>> I've been trying to create a simple test case to replicate this, but have not yet been successful.
>> It seems I need to run the big batch job, where the included module is 3600 lines long, and the
>> actual xquery is very long and complex as well.
>>
>> But the code snippet that causes this bug is static code in the common:test() function, and should
>> always return the correct result.
>>
>> I'm not sure what is causing this.  Could it be the new Binary Value caching/handling under weird
>> conditions that only happen when running under a scheduled task?  I've never managed to reproduce
>> this when calling xqueries directly (the ldap connection call is made all over the place in our web
>> app for authentication purposes).  Maybe util:binary-to-string() is at fault, but that seems
>> unlikely.  Maybe some of your path wrapper stuff?
>>
>> This exact same code runs just fine as a scheduled task in an older version of trunk (from late
>> summer last year), so it's definitely something new in trunk that has manifested since then.
>>
>> Any ideas on what might cause something this strange?  I has me very worried since this is pretty
>> basic stuff....and thus might cause other things like DB corruption, or incorrect values being
>> written or wrong logic paths being followed.
>>
>> I'll keep trying to create a simple test case that illustrates this, but I think it may not be
>> possible to do so.
>>
>> Help!
>>
>> Thanks!
>>
>> --
>> Andrzej Taramina
>> Chaeron Corporation: Enterprise System Solutions
>> http://www.chaeron.com
>>
> 
> 
> 


-- 
Andrzej Taramina
Chaeron Corporation: Enterprise System Solutions
http://www.chaeron.com

Re: [Exist-development] Very weird and serious error in trunk!

[Andrzej J. T. <an...@ch...>]

> Gonna try turning off the query optimizer and see if that makes any difference.

No effect turning off the query optimizer.  I still get the same problem with it turned off, so it's
not the query rewriter that is manifesting the issue.

.....A

> On 30 April 2011 00:55, Andrzej Jan Taramina <an...@ch...> wrote:
>> Wolfgang:
>>
>> I've hit a very weird error in trunk, that could potentially be very serious.
>>
>> I have some code in a module that looks like this:
>>
>> declare function common:test()
>> {
>>    let $line := <property name="java.naming.security.credentials"
>>                           value="{ util:binary-to-string( xs:base64Binary( 'dGVzdAoK' ) ) }"/>
>>
>>    let $debug2 := util:log-system-out( concat( "Credentials XML: ",
>>                        util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )
>>
>>    return $line
>> };
>>
>> declare function common:get-ldap-connection()  as xs:integer
>> {
>>    let $test := common:test()
>>
>>    let $contextProps :=
>>    <properties>
>>       <property name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>
>>       <property name="java.naming.provider.url"
>>                 value="{ common:get-config()/config/ldap/url/text() }"/>
>>       <property name="java.naming.security.authentication" value="simple"/>
>>       <property name="java.naming.security.principal"
>>                 value="{ common:get-config()/config/ldap/adminUser/text() }"/>
>>       <property name="java.naming.security.credentials"
>>                 value="{ util:binary-to-string( xs:base64Binary(
>>                                common:get-config()/config/ldap/adminPswd/text() ) ) }"/>
>>    </properties>
>>
>>    let $ctx := jndi:get-dir-context( $contextProps )
>>
>>    return $ctx
>> };
>>
>> I then have a xquery that includes this module, and does something like this:
>>
>>        let $cnx := common:get-ldap-connection()
>>
>> All works fine if I call this from the sandbox and in the console log I will see the following line
>> produced by the common:test() function:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials"
>>                                       value="test&#xA;&#xA;"/>
>>
>>
>> The problem I run into is that when I run this xquery from the scheduler (which is how it's intended
>> to run...it's a batch reporting job), cause then I get the following output in the console log:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials" value="test&#xA;&#xA;
>> test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA;
>> test&#xA;&#xA;"/>
>>
>> I get 8 concatenated decoded values in the value attribute!!!!
>>
>> This should never happen!!!!  Of course, in that situation, I fail to get an LDAP connection since
>> the password (the credentials) is a concatenation of 8 copies of the actual password, and so fails,
>> if I remove the call to the test function.  If I leave in the call to the test function, then the
>> correct (non-replicated) password is inserted into the credentials element of the $contextProps
>> variable. If I remove the test function call, then I get the same replication in $contextProps.
>>
>> What is weird is that the error only shows in the one place and is sensitive to order. If I put the
>> call to the test function after the construction of the $contextProps value, then $contextProps gets
>> the repeated value and the test function returns a correct, unrepeated value.
>>
>> I've been trying to create a simple test case to replicate this, but have not yet been successful.
>> It seems I need to run the big batch job, where the included module is 3600 lines long, and the
>> actual xquery is very long and complex as well.
>>
>> But the code snippet that causes this bug is static code in the common:test() function, and should
>> always return the correct result.
>>
>> I'm not sure what is causing this.  Could it be the new Binary Value caching/handling under weird
>> conditions that only happen when running under a scheduled task?  I've never managed to reproduce
>> this when calling xqueries directly (the ldap connection call is made all over the place in our web
>> app for authentication purposes).  Maybe util:binary-to-string() is at fault, but that seems
>> unlikely.  Maybe some of your path wrapper stuff?
>>
>> This exact same code runs just fine as a scheduled task in an older version of trunk (from late
>> summer last year), so it's definitely something new in trunk that has manifested since then.
>>
>> Any ideas on what might cause something this strange?  I has me very worried since this is pretty
>> basic stuff....and thus might cause other things like DB corruption, or incorrect values being
>> written or wrong logic paths being followed.
>>
>> I'll keep trying to create a simple test case that illustrates this, but I think it may not be
>> possible to do so.
>>
>> Help!
>>
>> Thanks!
>>
>> --
>> Andrzej Taramina
>> Chaeron Corporation: Enterprise System Solutions
>> http://www.chaeron.com
>>
> 
> 
> 


-- 
Andrzej Taramina
Chaeron Corporation: Enterprise System Solutions
http://www.chaeron.com

Re: [Exist-development] Very weird and serious error in trunk!

[Andrzej J. T. <an...@ch...>]

More testing on this issue:

I changed the test function to not use the Binary stuff, so it looks like this:

declare function common:test()
{
    let $line := <property name="java.naming.security.credentials"
	                   value="{ xs:string( 'dGVzdA==' ) }"/>

    let $debug2 := util:log-system-out( concat( "Credentials XML String: ",
		       util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )

    return $line
};

And I still get the erroneous result, with 8 repeated values:

(Line: 494) Credentials XML String: <property name="java.naming.security.credentials"
            value="dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA=="/>


So that means your Binary stuff is off the hook, Adam!  The problem is somewhere else....maybe in
the query parser or execution engine.

Changing the line that creates the xml snippet to:

   let $line := <property name="java.naming.security.credentials"
	                  value="{ let $tmp := 'dGVzdA==' return $tmp }"/>

shows the same issue....8 repeated strings, delimited with a space for the @value attribute.

But this variant does NOT repeat the values!

	let $tmp := 'dGVzdA=='

	let $line := <property name="java.naming.security.credentials" value="{ $tmp }"/>

and neither does this one:

	let $tmp := 'dGVzdA=='

    	let $line := <property name="java.naming.security.credentials"
			       value="{ xs:string( 'dGVzdA==' ) }"/>

Which leads me to believe that the bug is partially position sensitive.  If the creation of the xml
snippet is the first line of code in the function, then the values get replicated 8 times.  If there
is any code prior to that line, then it does not replicate.

I then changed the test function to take a parameter (the string being replicated) and changed the
calling function to pass in the string:

So this version:

declare function common:test( $tmp )
{
    let $line := <property name="java.naming.security.credentials" value="{ xs:string( $tmp ) }"/>

    .....
};

replicates the attribute value 8 times (showing the bug), but this one:

declare function common:test( $tmp )
{
    let $line := <property name="java.naming.security.credentials" value="{ $tmp }"/>

    .....
};

does not replicate (no bug!).

This leads me to believe that the bug is somewhere in how code fragments inside attribute values are
evaluated.

Not being very familiar with the xquery parser nor evaluation engine, I can't easily dive into the
code (which is very complex) to figure out what is going on. I'm hoping that all of these different
test cases might twig something with you, Wolfgang, since creating a simple test case to replicate
this is proving difficult.

.....Andrzej


> On 30 April 2011 00:55, Andrzej Jan Taramina <an...@ch...> wrote:
>> Wolfgang:
>>
>> I've hit a very weird error in trunk, that could potentially be very serious.
>>
>> I have some code in a module that looks like this:
>>
>> declare function common:test()
>> {
>>    let $line := <property name="java.naming.security.credentials"
>>                           value="{ util:binary-to-string( xs:base64Binary( 'dGVzdAoK' ) ) }"/>
>>
>>    let $debug2 := util:log-system-out( concat( "Credentials XML: ",
>>                        util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )
>>
>>    return $line
>> };
>>
>> declare function common:get-ldap-connection()  as xs:integer
>> {
>>    let $test := common:test()
>>
>>    let $contextProps :=
>>    <properties>
>>       <property name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>
>>       <property name="java.naming.provider.url"
>>                 value="{ common:get-config()/config/ldap/url/text() }"/>
>>       <property name="java.naming.security.authentication" value="simple"/>
>>       <property name="java.naming.security.principal"
>>                 value="{ common:get-config()/config/ldap/adminUser/text() }"/>
>>       <property name="java.naming.security.credentials"
>>                 value="{ util:binary-to-string( xs:base64Binary(
>>                                common:get-config()/config/ldap/adminPswd/text() ) ) }"/>
>>    </properties>
>>
>>    let $ctx := jndi:get-dir-context( $contextProps )
>>
>>    return $ctx
>> };
>>
>> I then have a xquery that includes this module, and does something like this:
>>
>>        let $cnx := common:get-ldap-connection()
>>
>> All works fine if I call this from the sandbox and in the console log I will see the following line
>> produced by the common:test() function:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials"
>>                                       value="test&#xA;&#xA;"/>
>>
>>
>> The problem I run into is that when I run this xquery from the scheduler (which is how it's intended
>> to run...it's a batch reporting job), cause then I get the following output in the console log:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials" value="test&#xA;&#xA;
>> test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA;
>> test&#xA;&#xA;"/>
>>
>> I get 8 concatenated decoded values in the value attribute!!!!
>>
>> This should never happen!!!!  Of course, in that situation, I fail to get an LDAP connection since
>> the password (the credentials) is a concatenation of 8 copies of the actual password, and so fails,
>> if I remove the call to the test function.  If I leave in the call to the test function, then the
>> correct (non-replicated) password is inserted into the credentials element of the $contextProps
>> variable. If I remove the test function call, then I get the same replication in $contextProps.
>>
>> What is weird is that the error only shows in the one place and is sensitive to order. If I put the
>> call to the test function after the construction of the $contextProps value, then $contextProps gets
>> the repeated value and the test function returns a correct, unrepeated value.
>>
>> I've been trying to create a simple test case to replicate this, but have not yet been successful.
>> It seems I need to run the big batch job, where the included module is 3600 lines long, and the
>> actual xquery is very long and complex as well.
>>
>> But the code snippet that causes this bug is static code in the common:test() function, and should
>> always return the correct result.
>>
>> I'm not sure what is causing this.  Could it be the new Binary Value caching/handling under weird
>> conditions that only happen when running under a scheduled task?  I've never managed to reproduce
>> this when calling xqueries directly (the ldap connection call is made all over the place in our web
>> app for authentication purposes).  Maybe util:binary-to-string() is at fault, but that seems
>> unlikely.  Maybe some of your path wrapper stuff?
>>
>> This exact same code runs just fine as a scheduled task in an older version of trunk (from late
>> summer last year), so it's definitely something new in trunk that has manifested since then.
>>
>> Any ideas on what might cause something this strange?  I has me very worried since this is pretty
>> basic stuff....and thus might cause other things like DB corruption, or incorrect values being
>> written or wrong logic paths being followed.
>>
>> I'll keep trying to create a simple test case that illustrates this, but I think it may not be
>> possible to do so.
>>
>> Help!
>>
>> Thanks!
>>
>> --
>> Andrzej Taramina
>> Chaeron Corporation: Enterprise System Solutions
>> http://www.chaeron.com
>>
> 
> 
> 


-- 
Andrzej Taramina
Chaeron Corporation: Enterprise System Solutions
http://www.chaeron.com

Re: [Exist-development] Very weird and serious error in trunk!

[Andrzej J. T. <an...@ch...>]

More testing on this issue:

I changed the test function to not use the Binary stuff, so it looks like this:

declare function common:test()
{
    let $line := <property name="java.naming.security.credentials"
	                   value="{ xs:string( 'dGVzdA==' ) }"/>

    let $debug2 := util:log-system-out( concat( "Credentials XML String: ",
		       util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )

    return $line
};

And I still get the erroneous result, with 8 repeated values:

(Line: 494) Credentials XML String: <property name="java.naming.security.credentials"
            value="dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA=="/>


So that means your Binary stuff is off the hook, Adam!  The problem is somewhere else....maybe in
the query parser or execution engine.

Changing the line that creates the xml snippet to:

   let $line := <property name="java.naming.security.credentials"
	                  value="{ let $tmp := 'dGVzdA==' return $tmp }"/>

shows the same issue....8 repeated strings, delimited with a space for the @value attribute.

But this variant does NOT repeat the values!

	let $tmp := 'dGVzdA=='

	let $line := <property name="java.naming.security.credentials" value="{ $tmp }"/>

and neither does this one:

	let $tmp := 'dGVzdA=='

    	let $line := <property name="java.naming.security.credentials"
			       value="{ xs:string( 'dGVzdA==' ) }"/>

Which leads me to believe that the bug is partially position sensitive.  If the creation of the xml
snippet is the first line of code in the function, then the values get replicated 8 times.  If there
is any code prior to that line, then it does not replicate.

I then changed the test function to take a parameter (the string being replicated) and changed the
calling function to pass in the string:

So this version:

declare function common:test( $tmp )
{
    let $line := <property name="java.naming.security.credentials" value="{ xs:string( $tmp ) }"/>

    .....
};

replicates the attribute value 8 times (showing the bug), but this one:

declare function common:test( $tmp )
{
    let $line := <property name="java.naming.security.credentials" value="{ $tmp }"/>

    .....
};

does not replicate (no bug!).

This leads me to believe that the bug is somewhere in how code fragments inside attribute values are
evaluated.

Not being very familiar with the xquery parser nor evaluation engine, I can't easily dive into the
code (which is very complex) to figure out what is going on. I'm hoping that all of these different
test cases might twig something with you, Wolfgang, since creating a simple test case to replicate
this is proving difficult.

.....Andrzej


> On 30 April 2011 00:55, Andrzej Jan Taramina <an...@ch...> wrote:
>> Wolfgang:
>>
>> I've hit a very weird error in trunk, that could potentially be very serious.
>>
>> I have some code in a module that looks like this:
>>
>> declare function common:test()
>> {
>>    let $line := <property name="java.naming.security.credentials"
>>                           value="{ util:binary-to-string( xs:base64Binary( 'dGVzdAoK' ) ) }"/>
>>
>>    let $debug2 := util:log-system-out( concat( "Credentials XML: ",
>>                        util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )
>>
>>    return $line
>> };
>>
>> declare function common:get-ldap-connection()  as xs:integer
>> {
>>    let $test := common:test()
>>
>>    let $contextProps :=
>>    <properties>
>>       <property name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>
>>       <property name="java.naming.provider.url"
>>                 value="{ common:get-config()/config/ldap/url/text() }"/>
>>       <property name="java.naming.security.authentication" value="simple"/>
>>       <property name="java.naming.security.principal"
>>                 value="{ common:get-config()/config/ldap/adminUser/text() }"/>
>>       <property name="java.naming.security.credentials"
>>                 value="{ util:binary-to-string( xs:base64Binary(
>>                                common:get-config()/config/ldap/adminPswd/text() ) ) }"/>
>>    </properties>
>>
>>    let $ctx := jndi:get-dir-context( $contextProps )
>>
>>    return $ctx
>> };
>>
>> I then have a xquery that includes this module, and does something like this:
>>
>>        let $cnx := common:get-ldap-connection()
>>
>> All works fine if I call this from the sandbox and in the console log I will see the following line
>> produced by the common:test() function:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials"
>>                                       value="test&#xA;&#xA;"/>
>>
>>
>> The problem I run into is that when I run this xquery from the scheduler (which is how it's intended
>> to run...it's a batch reporting job), cause then I get the following output in the console log:
>>
>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials" value="test&#xA;&#xA;
>> test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA;
>> test&#xA;&#xA;"/>
>>
>> I get 8 concatenated decoded values in the value attribute!!!!
>>
>> This should never happen!!!!  Of course, in that situation, I fail to get an LDAP connection since
>> the password (the credentials) is a concatenation of 8 copies of the actual password, and so fails,
>> if I remove the call to the test function.  If I leave in the call to the test function, then the
>> correct (non-replicated) password is inserted into the credentials element of the $contextProps
>> variable. If I remove the test function call, then I get the same replication in $contextProps.
>>
>> What is weird is that the error only shows in the one place and is sensitive to order. If I put the
>> call to the test function after the construction of the $contextProps value, then $contextProps gets
>> the repeated value and the test function returns a correct, unrepeated value.
>>
>> I've been trying to create a simple test case to replicate this, but have not yet been successful.
>> It seems I need to run the big batch job, where the included module is 3600 lines long, and the
>> actual xquery is very long and complex as well.
>>
>> But the code snippet that causes this bug is static code in the common:test() function, and should
>> always return the correct result.
>>
>> I'm not sure what is causing this.  Could it be the new Binary Value caching/handling under weird
>> conditions that only happen when running under a scheduled task?  I've never managed to reproduce
>> this when calling xqueries directly (the ldap connection call is made all over the place in our web
>> app for authentication purposes).  Maybe util:binary-to-string() is at fault, but that seems
>> unlikely.  Maybe some of your path wrapper stuff?
>>
>> This exact same code runs just fine as a scheduled task in an older version of trunk (from late
>> summer last year), so it's definitely something new in trunk that has manifested since then.
>>
>> Any ideas on what might cause something this strange?  I has me very worried since this is pretty
>> basic stuff....and thus might cause other things like DB corruption, or incorrect values being
>> written or wrong logic paths being followed.
>>
>> I'll keep trying to create a simple test case that illustrates this, but I think it may not be
>> possible to do so.
>>
>> Help!
>>
>> Thanks!
>>
>> --
>> Andrzej Taramina
>> Chaeron Corporation: Enterprise System Solutions
>> http://www.chaeron.com
>>
> 
> 
> 


-- 
Andrzej Taramina
Chaeron Corporation: Enterprise System Solutions
http://www.chaeron.com

Re: [Exist-development] Very weird and serious error in trunk!

[Andrzej J. T. <an...@ch...>]

Still happening with the latest fixes (BTree caching)....so it's not related to that.

....A

> More testing on this issue:
> 
> I changed the test function to not use the Binary stuff, so it looks like this:
> 
> declare function common:test()
> {
>     let $line := <property name="java.naming.security.credentials"
> 	                   value="{ xs:string( 'dGVzdA==' ) }"/>
> 
>     let $debug2 := util:log-system-out( concat( "Credentials XML String: ",
> 		       util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )
> 
>     return $line
> };
> 
> And I still get the erroneous result, with 8 repeated values:
> 
> (Line: 494) Credentials XML String: <property name="java.naming.security.credentials"
>             value="dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA== dGVzdA=="/>
> 
> 
> So that means your Binary stuff is off the hook, Adam!  The problem is somewhere else....maybe in
> the query parser or execution engine.
> 
> Changing the line that creates the xml snippet to:
> 
>    let $line := <property name="java.naming.security.credentials"
> 	                  value="{ let $tmp := 'dGVzdA==' return $tmp }"/>
> 
> shows the same issue....8 repeated strings, delimited with a space for the @value attribute.
> 
> But this variant does NOT repeat the values!
> 
> 	let $tmp := 'dGVzdA=='
> 
> 	let $line := <property name="java.naming.security.credentials" value="{ $tmp }"/>
> 
> and neither does this one:
> 
> 	let $tmp := 'dGVzdA=='
> 
>     	let $line := <property name="java.naming.security.credentials"
> 			       value="{ xs:string( 'dGVzdA==' ) }"/>
> 
> Which leads me to believe that the bug is partially position sensitive.  If the creation of the xml
> snippet is the first line of code in the function, then the values get replicated 8 times.  If there
> is any code prior to that line, then it does not replicate.
> 
> I then changed the test function to take a parameter (the string being replicated) and changed the
> calling function to pass in the string:
> 
> So this version:
> 
> declare function common:test( $tmp )
> {
>     let $line := <property name="java.naming.security.credentials" value="{ xs:string( $tmp ) }"/>
> 
>     .....
> };
> 
> replicates the attribute value 8 times (showing the bug), but this one:
> 
> declare function common:test( $tmp )
> {
>     let $line := <property name="java.naming.security.credentials" value="{ $tmp }"/>
> 
>     .....
> };
> 
> does not replicate (no bug!).
> 
> This leads me to believe that the bug is somewhere in how code fragments inside attribute values are
> evaluated.
> 
> Not being very familiar with the xquery parser nor evaluation engine, I can't easily dive into the
> code (which is very complex) to figure out what is going on. I'm hoping that all of these different
> test cases might twig something with you, Wolfgang, since creating a simple test case to replicate
> this is proving difficult.
> 
> .....Andrzej
> 
> 
>> On 30 April 2011 00:55, Andrzej Jan Taramina <an...@ch...> wrote:
>>> Wolfgang:
>>>
>>> I've hit a very weird error in trunk, that could potentially be very serious.
>>>
>>> I have some code in a module that looks like this:
>>>
>>> declare function common:test()
>>> {
>>>    let $line := <property name="java.naming.security.credentials"
>>>                           value="{ util:binary-to-string( xs:base64Binary( 'dGVzdAoK' ) ) }"/>
>>>
>>>    let $debug2 := util:log-system-out( concat( "Credentials XML: ",
>>>                        util:serialize(  $line, "method=xml media-type=text/xml indent=yes" ) ) )
>>>
>>>    return $line
>>> };
>>>
>>> declare function common:get-ldap-connection()  as xs:integer
>>> {
>>>    let $test := common:test()
>>>
>>>    let $contextProps :=
>>>    <properties>
>>>       <property name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>
>>>       <property name="java.naming.provider.url"
>>>                 value="{ common:get-config()/config/ldap/url/text() }"/>
>>>       <property name="java.naming.security.authentication" value="simple"/>
>>>       <property name="java.naming.security.principal"
>>>                 value="{ common:get-config()/config/ldap/adminUser/text() }"/>
>>>       <property name="java.naming.security.credentials"
>>>                 value="{ util:binary-to-string( xs:base64Binary(
>>>                                common:get-config()/config/ldap/adminPswd/text() ) ) }"/>
>>>    </properties>
>>>
>>>    let $ctx := jndi:get-dir-context( $contextProps )
>>>
>>>    return $ctx
>>> };
>>>
>>> I then have a xquery that includes this module, and does something like this:
>>>
>>>        let $cnx := common:get-ldap-connection()
>>>
>>> All works fine if I call this from the sandbox and in the console log I will see the following line
>>> produced by the common:test() function:
>>>
>>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials"
>>>                                       value="test&#xA;&#xA;"/>
>>>
>>>
>>> The problem I run into is that when I run this xquery from the scheduler (which is how it's intended
>>> to run...it's a batch reporting job), cause then I get the following output in the console log:
>>>
>>> (Line: 494) Credentials XML: <property name="java.naming.security.credentials" value="test&#xA;&#xA;
>>> test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA; test&#xA;&#xA;
>>> test&#xA;&#xA;"/>
>>>
>>> I get 8 concatenated decoded values in the value attribute!!!!
>>>
>>> This should never happen!!!!  Of course, in that situation, I fail to get an LDAP connection since
>>> the password (the credentials) is a concatenation of 8 copies of the actual password, and so fails,
>>> if I remove the call to the test function.  If I leave in the call to the test function, then the
>>> correct (non-replicated) password is inserted into the credentials element of the $contextProps
>>> variable. If I remove the test function call, then I get the same replication in $contextProps.
>>>
>>> What is weird is that the error only shows in the one place and is sensitive to order. If I put the
>>> call to the test function after the construction of the $contextProps value, then $contextProps gets
>>> the repeated value and the test function returns a correct, unrepeated value.
>>>
>>> I've been trying to create a simple test case to replicate this, but have not yet been successful.
>>> It seems I need to run the big batch job, where the included module is 3600 lines long, and the
>>> actual xquery is very long and complex as well.
>>>
>>> But the code snippet that causes this bug is static code in the common:test() function, and should
>>> always return the correct result.
>>>
>>> I'm not sure what is causing this.  Could it be the new Binary Value caching/handling under weird
>>> conditions that only happen when running under a scheduled task?  I've never managed to reproduce
>>> this when calling xqueries directly (the ldap connection call is made all over the place in our web
>>> app for authentication purposes).  Maybe util:binary-to-string() is at fault, but that seems
>>> unlikely.  Maybe some of your path wrapper stuff?
>>>
>>> This exact same code runs just fine as a scheduled task in an older version of trunk (from late
>>> summer last year), so it's definitely something new in trunk that has manifested since then.
>>>
>>> Any ideas on what might cause something this strange?  I has me very worried since this is pretty
>>> basic stuff....and thus might cause other things like DB corruption, or incorrect values being
>>> written or wrong logic paths being followed.
>>>
>>> I'll keep trying to create a simple test case that illustrates this, but I think it may not be
>>> possible to do so.
>>>
>>> Help!
>>>
>>> Thanks!
>>>
>>> --
>>> Andrzej Taramina
>>> Chaeron Corporation: Enterprise System Solutions
>>> http://www.chaeron.com
>>>
>>
>>
>>
> 
> 


-- 
Andrzej Taramina
Chaeron Corporation: Enterprise System Solutions
http://www.chaeron.com