Bug #91898 for REST-Neo4p: Auto-commit

Mon Jan 06 11:40:07 2014 symonsjo [...] gmail.com - Ticket created

Subject:

Auto-commit

Perhaps this isn't a bug but an intended feature. I'm interested in the behaviour of auto-commit in that I've been tracing my transaction and seen the following from the strace for read and write (write written but followed by 4 commit reads). Code base here: http://pastebin.com/Vw5MEbTV Example strace output: 1389025953.610132 write(27, "POST /db/data/transaction/487494 HTTP/1.1\r\nTE: deflate,gzip;q=0.3\r\nConnection: TE, close\r\nAccept: application/json\r\nHost: localhost:7474\r\nUser-Agent: Neo4p/0.2230\r\nContent-Length: 738\r\nContent-Type: application/json\r\nX-Stream: true\r\n\r\n{\"statements\":[{\"statement\":\"MERGE (i:INCIDENT { incident_id : { incident_id } }) ON CREATE SET i.incident_timestamp = { incident_timestamp }, i.incident_description = { incident_description } RETURN i.incident_id \",\"parameters\":{\"incident_timestamp\":\"2006-10-09T12:00:00\",\"incident_description\":\"_masked_incident_description_\",\"incident_id\":\"_masked_incident_id_\"}}]}", 973) = 973 <0.000124> 1389025953.611573 read(27, "HTTP/1.1 200 OK\r\nContent-Encoding: UTF-8\r\nContent-Type: application/json\r\nAccess-Control-Allow-Origin: *\r\nConnection: close\r\nServer: Jetty(9.0.5.v20130815)\r\n\r\n{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"_masked_incident_description_\"]}]}],\"transaction\":{\"expires\":\"Mon, 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 1024) = 370 <0.000040> 1389025953.613176 read(27, "", 4096) = 0 <0.000019> 1389025953.613745 write(28, "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"_masked_incident_description_\"]}]}],\"transaction\":{\"expires\":\"Mon, 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 211) = 211 <0.000073> 1389025953.614761 read(16, "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"1211854\"]}]}],\"transaction\":{\"expires\":\"Mon, 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 4096) = 211 <0.000037> 1389025953.619427 read(16, "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"_masked_incident_description_\"]}]}],\"transaction\":{\"expires\":\"Mon, 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 4096) = 211 <0.000109> 1389025953.624736 read(16, "", 4096) = 0 <0.000025> 1389025953.624996 read(16, "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"1211854\"]}]}],\"transaction\":{\"expires\":\"Mon, 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 4096) = 211 <0.000018> Maybe this is just normal behaviour but when I'm looking at it from the perspective of write and read (post/post) it takes 0.001441 seconds.microseconds for that portion, but when the subsequent commit reads are included it takes a total of 0.014864 seconds.microseconds. Is this a mistake on how I'm reading it or can you turn off auto-commit to alleviate this portion and simply do the end-commit similar to how you would in java (commit=False https://neo4j-rest-client.readthedocs.org/en/latest/transactions.html see section on auto-update/auto-commit).

Sat Jan 18 22:01:32 2014 maj.fortinbras [...] gmail.com - Correspondence added

Hi icenine, I'm having trouble interpreting the trace. There is a write to fd 27 of the request, and a read of the initial response from fd 27. Then there is an additional write to fd 28 of what looks like a response from the server. This may be a storage of that response to a file. The other reads (from fd 16) are hard to interpret. One thing I notice is that the value for incident_id is returned as 1211854 from the server in 2 cases and as "_masked_incident_description_" in another case. The additional reads could be additional executions of the same query, with different parameters. But it's hard to tell exactly what's going on- MAJ On Mon Jan 06 11:40:07 2014, symonsjo@gmail.com wrote: Show quoted text

> Perhaps this isn't a bug but an intended feature. I'm interested in > the behaviour of auto-commit in that I've been tracing my transaction > and seen the following from the strace for read and write (write > written but followed by 4 commit reads). > > Code base here: http://pastebin.com/Vw5MEbTV > > Example strace output: > > 1389025953.610132 write(27, "POST /db/data/transaction/487494 > HTTP/1.1\r\nTE: deflate,gzip;q=0.3\r\nConnection: TE, close\r\nAccept: > application/json\r\nHost: localhost:7474\r\nUser-Agent: > Neo4p/0.2230\r\nContent-Length: 738\r\nContent-Type: > application/json\r\nX-Stream: > true\r\n\r\n{\"statements\":[{\"statement\":\"MERGE (i:INCIDENT { > incident_id : { incident_id } }) ON CREATE SET i.incident_timestamp = > { incident_timestamp }, i.incident_description = { > incident_description } RETURN i.incident_id > \",\"parameters\":{\"incident_timestamp\":\"2006-10- > 09T12:00:00\",\"incident_description\":\"_masked_incident_description_\",\"incident_id\":\"_masked_incident_id_\"}}]}", > 973) = 973 <0.000124> > 1389025953.611573 read(27, "HTTP/1.1 200 OK\r\nContent-Encoding: UTF- > 8\r\nContent-Type: application/json\r\nAccess-Control-Allow-Origin: > *\r\nConnection: close\r\nServer: > Jetty(9.0.5.v20130815)\r\n\r\n{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"_masked_incident_description_\"]}]}],\"transaction\":{\"expires\":\"Mon, > 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 1024) = 370 <0.000040> > 1389025953.613176 read(27, "", 4096) = 0 <0.000019> > 1389025953.613745 write(28, > "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"_masked_incident_description_\"]}]}],\"transaction\":{\"expires\":\"Mon, > 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 211) = 211 <0.000073> > 1389025953.614761 read(16, > "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"1211854\"]}]}],\"transaction\":{\"expires\":\"Mon, > 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 4096) = 211 <0.000037> > 1389025953.619427 read(16, > "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"_masked_incident_description_\"]}]}],\"transaction\":{\"expires\":\"Mon, > 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 4096) = 211 <0.000109> > 1389025953.624736 read(16, "", 4096) = 0 <0.000025> > 1389025953.624996 read(16, > "{\"commit\":\"http://localhost:7474/db/data/transaction/487494/commit\",\"results\":[{\"columns\":[\"i.incident_id\"],\"data\":[{\"row\":[\"1211854\"]}]}],\"transaction\":{\"expires\":\"Mon, > 06 Jan 2014 16:33:33 +0000\"},\"errors\":[]}", 4096) = 211 <0.000018> > > Maybe this is just normal behaviour but when I'm looking at it from > the perspective of write and read (post/post) it takes 0.001441 > seconds.microseconds for that portion, but when the subsequent commit > reads are included it takes a total of 0.014864 seconds.microseconds. > Is this a mistake on how I'm reading it or can you turn off auto- > commit to alleviate this portion and simply do the end-commit similar > to how you would in java (commit=False https://neo4j-rest- > client.readthedocs.org/en/latest/transactions.html see section on > auto-update/auto-commit).

Sat Jan 18 22:01:32 2014 The RT System itself - Status changed from 'new' to 'open'

Wed Aug 06 00:13:57 2014 maj.fortinbras [...] gmail.com - Status changed from 'open' to 'stalled'