APOC procedures are called random number of times

[cleishm]

APOC procedures are called random number of times

[cleishm]

Hi @justmag,

The results from cypher statements are determined entirely by the server. You can confirm that it is the server returning the unexpected result count by enabling trace logging (using -vvv) and observing the raw responses from the server.

As such, you'll get the same problem regardless of which shell you use.

You may want to raise an issue with the APOC repository to see if they can help you determine why the result is incorrect.

[justmag]

it looks like the problem arises only in "batch " mode
everything is fine when I enter commands in the client manually

I called client with -vvv in the batch file
neo4j-client -u login -p password -P localhost -vvv < input.file
the answer again is random and incorrect, see debug log for the command below

DEBUG [connection]: attempting connection to ::1 [7687]
INFO [connection]: connection to ::1 [7687] failed: Connection refused
DEBUG [connection]: attempting connection to 127.0.0.1 [7687]
TRACE [connection]: opened socket to localhost [7687] (fd=4)
TRACE [connection]: initialiting TLS (fd=4)
DEBUG [tls]: server cert fingerprint: fc86c0f9531415bc4bece89651a88948c27c92ae4cc8aa5fdef71d9ef2d41cdc82bf38afe1376edefc81a41f5dece5c741a03d47ec946a849208ba070601925b
DEBUG [tls]: TLS certificate verification failed: self signed certificate
INFO [connection]: connected (0x55d5749420c0) to localhost:7687
DEBUG [connection]: connection 0x55d5749420c0 using protocol version 1
TRACE [connection]: enqu INIT{"libneo4j-client/2.1.3", {scheme: basic, principal: "neo4j", credentials: ****}} (0x55d574942550) in 0x55d5749420c0
DEBUG [connection]: sent INIT (0x55d574942550) in 0x55d5749420c0
DEBUG [connection]: rcvd SUCCESS in response to INIT (0x55d574942550)
TRACE [connection]: SUCCESS in 0x55d5749420c0 (response to INIT): {server:"Neo4j/3.2.1"}
.................................

TRACE [connection]: enqu PULL_ALL (0x556214bea150) in 0x556214be80c0
DEBUG [connection]: rcvd SUCCESS in response to RUN (0x556214be9970)
TRACE [results]: SUCCESS in 0x556214be80c0 (response to RUN): {result_available_after:72,fields:["count (rel)"]}
DEBUG [connection]: sent RUN (0x556214bea070) in 0x556214be80c0
DEBUG [connection]: sent PULL_ALL (0x556214bea150) in 0x556214be80c0
"count (rel)"
DEBUG [connection]: rcvd RECORD in response to PULL_ALL (0x556214be9a50)
112

the answer to the request is 112, next call it will be e.g. 7
the right answer is 123310

Please confirm that these commands are sent to the server properly
BR, Max

N.B.!
the issue is actual with neo4j 3.2.1 on Ubuntu 16.04.2 LTS
I do not have the problem on MAC OS X 10.11.6 and neo4j 3.2.0

[cleishm]

Hi @justmag,

I can't confirm that it was sent correctly, as you've left out some of the debug lines (specifically the 'sent RUN' line). But it looks correct, and the result of 112 is definitely returned by the server.

Using batch mode does pipeline requests to the server, which means they are executed immediately after the previous. Perhaps the interactive mode gives the server a chance to settle down and update its caches. Either way, this seems like a bug in the procedure or in the server itself.

That said, it is odd that you say it does not have an issue when using Mac OS X. Do you mean you're running neo4j server on Mac OS X, and it works? And when you're running neo4j server on Ubuntu, it doesn't? Or do you mean you're running neo4j-client on those, against the same server?

Perhaps you can describe each configuration in more detail, and include the complete trace logs from the client in each situation.

Cheers,
Chris

[jexp]

Also, your command is very unusual, do you intend to create relationships between all changes in the database to a single file?

match (c:Change)-->(a:Code_change), (f:File{name:a.file_path})
call apoc.create.relationship(c,toString(a.change_type), {add_lines:toInteger(a.sum_added_lines),
rem_lines:toInteger(a.sum_removed_lines)},f) yield rel
return count (rel);

The count is not so much determined by the procedure as by your MATCH patterns, it basically counts the paths returned between the node-pair and all the File nodes it finds with this file-path.

Not sure if when running in batch-mode, it uses transactions or not?

The procedure is very simplistic, it keeps no state or such, so it should have no effect.

[cleishm]

@jexp Thanks for popping in!

Batch mode doesn't do any implicit transactions: transactions must always be explicit using begin and commit statements. The only difference in batch mode is that requests are pipelined and the default output format is set to csv.

[justmag]

hi, thanks for the reply,

the servers and clients are running on the same machines : MAC or Ubuntu respectively.
the idea of the query:
there are 2 objects: Chane and Code_change and they are connected with the direction.
The latter contain references to file names (another type of objects in the database : File)

I want to create relations between objects Change and respective Files, where file_names of the respective files are determined by the intermediary object's (Code_change) properties "file_path"

the 1st match produces sets of objects Change and respective linked Code_change; the second- all RESPECTIVE (?) objects File that are linked to the Code_change and thus, to object Change too.
Then, I simply create the relations Change-->File with the APOC procedure, adding properties taken from object Code_change . (regrettably, there is no native function in neo4j for that).
As I tested in neo4j browser, the result is satisfactory - all seem to connect properly.

I do not use transactions explicitly.
But I do not use them in cypher-shell either, yet the result is always the same and correct.
it is always correct on MAC & neo4j 3.2.0 too.

to cleishm :
I used -vvv parameter and do not know how to get full trace logs.
the extract above is what I exactly got on the screen using that parameter: i did not cut anything.
That was from the Ubuntu & neo4j 3.2.1

p.s.
:begin;

match (c:Change)-->(a:Code_change), (f:File{name:a.file_path})
call apoc.create.relationship(c,toString(a.change_type), {add_lines:toInteger(a.sum_added_lines),
rem_lines:toInteger(a.sum_removed_lines)},f) yield rel
return count (rel);

:commit;

had no effect:
.........................
DEBUG [connection]: rcvd SUCCESS in response to PULL_ALL (0x56102e60ac10)
TRACE [results]: SUCCESS in 0x56102e6090c0 (response to PULL_ALL): {bookmark:"neo4j🔖v1:tx3216"}
TRACE [connection]: enqu RUN{"begin", {}} (0x56102e60acf0) in 0x56102e6090c0
TRACE [connection]: enqu PULL_ALL (0x56102e60add0) in 0x56102e6090c0
DEBUG [connection]: sent RUN (0x56102e60acf0) in 0x56102e6090c0
DEBUG [connection]: sent PULL_ALL (0x56102e60add0) in 0x56102e6090c0
DEBUG [connection]: rcvd SUCCESS in response to RUN (0x56102e60acf0)
TRACE [results]: SUCCESS in 0x56102e6090c0 (response to RUN): {result_available_after:0,fields:[]}
DEBUG [connection]: rcvd SUCCESS in response to PULL_ALL (0x56102e60add0)
TRACE [results]: SUCCESS in 0x56102e6090c0 (response to PULL_ALL): {}
TRACE [connection]: enqu RUN{"match (c:Change)-->(a:Code_change), (f:File{name:a.file_path})
call apoc.create.relationship(c,toString(a.change_type), {add_lines:toInteger(a.sum_added_lines),
rem_lines:toInteger(a.sum_removed_lines)},f) yield rel
return count (rel)", {}} (0x56102e60aeb0) in 0x56102e6090c0
TRACE [connection]: enqu PULL_ALL (0x56102e60af90) in 0x56102e6090c0
DEBUG [connection]: sent RUN (0x56102e60aeb0) in 0x56102e6090c0
DEBUG [connection]: sent PULL_ALL (0x56102e60af90) in 0x56102e6090c0
DEBUG [connection]: rcvd SUCCESS in response to RUN (0x56102e60aeb0)
TRACE [results]: SUCCESS in 0x56102e6090c0 (response to RUN): {result_available_after:69,fields:["count (rel)"]}
"count (rel)"
DEBUG [connection]: rcvd RECORD in response to PULL_ALL (0x56102e60af90)
105
DEBUG [connection]: rcvd SUCCESS in response to PULL_ALL (0x56102e60af90)
TRACE [results]: SUCCESS in 0x56102e6090c0 (response to PULL_ALL): {result_consumed_after:0,type:"rw"}
TRACE [connection]: enqu RUN{"commit", {}} (0x56102e60b070) in 0x56102e6090c0
TRACE [connection]: enqu PULL_ALL (0x56102e60b150) in 0x56102e6090c0
DEBUG [connection]: sent RUN (0x56102e60b070) in 0x56102e6090c0
DEBUG [connection]: sent PULL_ALL (0x56102e60b150) in 0x56102e6090c0
DEBUG [connection]: rcvd SUCCESS in response to RUN (0x56102e60b070)
TRACE [results]: SUCCESS in 0x56102e6090c0 (response to RUN): {result_available_after:6,fields:[]}
......................
BR, Max

[cleishm]

Hey @justmag,

That trace shows the statements being sent consecutively, and the response (105) is coming back from the server. If that response is wrong, the only explanation is a problem at the server side.

[cleishm]

Closing this, as it cannot be reproduced.