I have a Neo4j 3.5.3 installation on my Ubuntu laptop (which is Intel i5, 4 GB RAM, SSD disk) and I'm trying to import a moderate-sized dataset from CSV files into the graph.
Here is the full Cypher script I use:
MATCH (x :Shop ) DETACH DELETE x RETURN count(*) AS DeletedShops;
MATCH (x :Postal ) DETACH DELETE x RETURN count(*) AS DeletedPostal;
MATCH (x :City ) DETACH DELETE x RETURN count(*) AS DeletedCities;
MATCH (x :Locator ) DETACH DELETE x RETURN count(*) AS DeletedLocators;
MATCH (x :Brand ) DETACH DELETE x RETURN count(*) AS DeletedBrands;
MATCH (x :Industry ) DETACH DELETE x RETURN count(*) AS DeletedIndustries;
USING PERIODIC COMMIT 10000
LOAD CSV WITH HEADERS FROM 'file:///accounts.csv.gz' AS csv
//locatorschemaname,accountname,clientname,clientindustry,accountindustry,locationcount
MERGE (b:Brand {name: csv.clientname})
FOREACH(n IN (CASE WHEN csv.clientindustry IS NOT NULL AND NOT toLower(csv.clientindustry) IN ['na','unknown','other'] THEN [1] ELSE [] END) |
MERGE (i:Industry {name: csv.clientindustry})
MERGE (b)-[:INDUSTRY]->(i)
)
FOREACH(n IN (CASE WHEN csv.accountindustry IS NOT NULL AND NOT toLower(csv.accountindustry) IN ['na','unknown','other'] THEN [1] ELSE [] END) |
MERGE (i2:Industry {name: csv.accountindustry})
MERGE (b)-[:INDUSTRY]->(i2)
)
// Brand.shops = max(locator.shops)
FOREACH(n IN (CASE WHEN csv.locatorschemaname IS NOT NULL AND csv.locatorschemaname=csv.accountname THEN [1] ELSE [] END) |
MERGE (l:Locator {name: csv.locatorschemaname, shops: toInt(csv.locationcount)})
MERGE (l)-[:BRAND]->(b)
SET b.shops = CASE
WHEN b.shops IS NULL OR b.shops < toInt(csv.locationcount) THEN toInt(csv.locationcount) ELSE b.shops END
);
MATCH (:Industry) RETURN count(*) AS IndustriesCreated;
MATCH (:Brand) RETURN count(*) AS BrandsCreated;
MATCH (:Locator) RETURN count(*) AS LocatorsCreated;
// Industry.shops = sum(Brand.shops)
MATCH (b:Brand)-[:INDUSTRY]->(i:Industry)
WITH i.name AS iname, sum(b.shops) AS isum
MATCH (ii:Industry {name: iname})
SET ii.shops = isum;
// NOTE: This is done in multiple-pass mode, to avoid performance issues with NEo4j CE 3.4.7 on ubuntu
// NOTE: We do not use WITH HEADERS as it adds a 40%+ overhead
// PASS 1. Shops
USING PERIODIC COMMIT 10000
LOAD CSV FROM 'file:///locations.csv.gz' AS csv
// schemaname,clientkey,name,address1,address2,city,region,country,postalcode,latitude,longitude
// find existing locator node
MATCH (l :Locator {name: csv[0]})
CREATE (s:Shop {
locatorname: csv[0],
clientkey: csv[1],
latitude: toFloat(csv[9]),
longitude: toFloat(csv[10])
})
CREATE (s)-[:LOCATOR]->(l);
CREATE INDEX ON :Shop (locatorname, clientkey);
MATCH (:Shop) RETURN count(*) AS ShopsCreated;
// PASS 2. cities
USING PERIODIC COMMIT 10000
LOAD CSV FROM 'file:///locations.csv.gz' AS csv
WITH csv WHERE csv[5] IS NOT NULL
MATCH (s:Shop {locatorname: csv[0], clientkey: csv[1]})
MERGE (city :City {name: csv[5], country: csv[7]}) ON CREATE SET city.region = csv[6]
MERGE (s)-[:CITY]->(city);
MATCH (:City) RETURN count(*) AS CitiesCreated;
// PASS 3. postal codes
USING PERIODIC COMMIT 10000
LOAD CSV FROM 'file:///locations.csv.gz' AS csv
WITH csv WHERE csv[8] IS NOT NULL
MATCH (s:Shop {locatorname: csv[0], clientkey: csv[1]})
MERGE (postal :Postal {name: csv[8], country: csv[7]}) ON CREATE SET postal.region = csv[6]
MERGE (s)-[:POSTAL]->(postal);
MATCH (:Postal) RETURN count(*) AS PostalcodesCreated;
CREATE CONSTRAINT ON (i:Industry) ASSERT i.name IS UNIQUE;
CREATE CONSTRAINT ON (b:Brand) ASSERT b.name IS UNIQUE;
CREATE CONSTRAINT ON (l:Locator) ASSERT l.name IS UNIQUE;
The problem is, the scripts makes it fairly quickly to the end of "PASS 1", and then it apparently hangs on "PASS 2". The server process is churning CPU and nothing visible happens. This lasts at least 120 minutes and does not look like it's going to finish any time soon.
I use default settings for heap size etc. But on-disk size of the whole dataset (checked in /var/lib/neo4j/data) is ~~ 500 MB. So this machine should handle it.
Here is the output so far:
DeletedShops
0
DeletedPostal
0
DeletedCities
0
DeletedLocators
0
DeletedBrands
0
DeletedIndustries
0
IndustriesCreated
18
BrandsCreated
1326
LocatorsCreated
2092
ShopsCreated
937488
// very long wait here
And here is some ps output:
[11:50:56][filip@lap2:~/neo4j]$ ps fuwww `pidof java`
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
filip 4966 0.0 0.1 3979904 7412 pts/0 Sl+ 08:57 0:09 /usr/lib/jvm/java-8-oracle/bin/java -jar /usr/bin/../share/cypher-shell/lib/cypher-shell-all.jar -u neo4j -p neo --format plain
neo4j 2411 98.1 25.6 4862652 1012488 ? Ssl 08:50 177:11 /usr/bin/java -cp /var/lib/neo4j/plugins:/etc/neo4j:/usr/share/neo4j/lib/*:/var/lib/neo4j/plugins/* -server -Xms950m -Xmx950m -XX:+UseG1GC -XX:-OmitStackTraceInFastThrow -XX:+AlwaysPreTouch -XX:+UnlockExperimentalVMOptions -XX:+TrustFinalNonStaticFields -XX:+DisableExplicitGC -Djdk.tls.ephemeralDHKeySize=2048 -Djdk.tls.rejectClientInitiatedRenegotiation=true -Dunsupported.dbms.udc.source=debian -Dfile.encoding=UTF-8 org.neo4j.server.CommunityEntryPoint --home-dir=/var/lib/neo4j --config-dir=/etc/neo4j
How can I rewrite the script to achieve same thing faster?
What can I do to diagnose the bottleneck?
Is this at all doable using limited (1-2 GB) java heap size - and why not?
Update: here is result of a short strace -v -tt -f -s 100 -p <PID_OF_SERVER>:
5020 13:04:53.108793 epoll_wait(238, <unfinished ...>
5013 13:04:53.108847 epoll_wait(235, <unfinished ...>
4887 13:04:53.108865 epoll_wait(232, <unfinished ...>
4879 13:04:53.108874 epoll_wait(229, <unfinished ...>
4617 13:04:53.108890 epoll_wait(226, <unfinished ...>
4590 13:04:53.108897 epoll_wait(223, <unfinished ...>
3557 13:04:53.108916 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
3016 13:04:53.108925 restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
3015 13:04:53.108942 restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
3014 13:04:53.108950 restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
3013 13:04:53.108966 accept(256, <unfinished ...>
3012 13:04:53.108981 epoll_wait(263, <unfinished ...>
3011 13:04:53.108998 epoll_wait(260, <unfinished ...>
3010 13:04:53.109006 accept(248, <unfinished ...>
3009 13:04:53.109023 epoll_wait(255, <unfinished ...>
3008 13:04:53.109032 epoll_wait(252, <unfinished ...>
3007 13:04:53.109047 restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
3005 13:04:53.109055 epoll_wait(220, <unfinished ...>
3001 13:04:53.109083 futex(0x7efc2999783c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
3000 13:04:53.109098 futex(0x7efc29995d0c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2999 13:04:53.109116 futex(0x7efc2996e7d8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2998 13:04:53.109125 futex(0x7efc2996eb68, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2997 13:04:53.109141 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2996 13:04:53.109149 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2995 13:04:53.109166 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2994 13:04:53.109174 futex(0x7efc298c8df8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2993 13:04:53.109190 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2992 13:04:53.109198 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2991 13:04:53.109214 restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
2990 13:04:53.109222 restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
2989 13:04:53.109239 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2951 13:04:53.109248 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2950 13:04:53.109266 futex(0x7efc2843f37c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2949 13:04:53.109274 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2948 13:04:53.109290 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2947 13:04:53.109299 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2946 13:04:53.109316 futex(0x7efc30ba6580, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, 0xffffffff <unfinished ...>
2945 13:04:53.109325 futex(0x7efc2842bb7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2932 13:04:53.109342 futex(0x7efc283f3f7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2927 13:04:53.109351 futex(0x7efc283f157c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2924 13:04:53.109369 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2621 13:04:53.109377 futex(0x7efc28048278, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2620 13:04:53.109395 futex(0x7efc28046578, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2619 13:04:53.109405 futex(0x7efc2803607c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2618 13:04:53.109423 futex(0x7efc28034378, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2617 13:04:53.109432 futex(0x7efc2803277c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2616 13:04:53.109449 futex(0x7efc28030b7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2615 13:04:53.109458 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
2614 13:04:53.109476 futex(0x7efc2802c67c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2613 13:04:53.109485 futex(0x7efc2802aa78, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2612 13:04:53.109507 futex(0x7efc28028e78, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2611 13:04:53.109517 futex(0x7efc28027278, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2610 13:04:53.109536 futex(0x7efc2800fb78, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2411 13:04:53.109545 futex(0x7efc317f19d0, FUTEX_WAIT, 2610, NULL <unfinished ...>
2992 13:04:53.115544 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.115730 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.115828 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998460} <unfinished ...>
2997 13:04:53.118313 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
2997 13:04:53.118352 futex(0x7efc298e0128, FUTEX_WAKE_PRIVATE, 1) = 0
2997 13:04:53.118394 futex(0x7efc298e0178, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=99998722} <unfinished ...>
2951 13:04:53.125119 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
2951 13:04:53.125180 futex(0x7efc28442a28, FUTEX_WAKE_PRIVATE, 1) = 0
2951 13:04:53.125217 futex(0x7efc28442a78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=49998764} <unfinished ...>
2992 13:04:53.126016 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.126360 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.126435 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9996862}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.136631 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.136735 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9997659}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.146911 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.147016 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998199}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.157194 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.157259 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998611}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.167441 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.167505 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998486} <unfinished ...>
2951 13:04:53.175350 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2951 13:04:53.175419 futex(0x7efc28442a28, FUTEX_WAKE_PRIVATE, 1) = 0
2951 13:04:53.175469 futex(0x7efc28442a78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=49999014} <unfinished ...>
2992 13:04:53.177624 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.177661 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.177704 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998753}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.187869 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.187926 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998345}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.198107 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.198173 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998906}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.208351 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.208445 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998819} <unfinished ...>
2997 13:04:53.218546 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.218607 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2997 13:04:53.218627 futex(0x7efc298e0128, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2992 13:04:53.218642 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2997 13:04:53.218654 <... futex resumed> ) = 0
2992 13:04:53.218665 <... futex resumed> ) = 0
2997 13:04:53.218692 futex(0x7efc298e0178, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=99997816} <unfinished ...>
2992 13:04:53.218716 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998951} <unfinished ...>
2951 13:04:53.225620 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2951 13:04:53.225685 futex(0x7efc28442a28, FUTEX_WAKE_PRIVATE, 1) = 0
2951 13:04:53.225726 futex(0x7efc28442a78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=49998661} <unfinished ...>
2992 13:04:53.228844 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.228894 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.228977 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998496}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.239167 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.239237 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9997919} <unfinished ...>
2615 13:04:53.248889 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
2615 13:04:53.248964 futex(0x7efc2802ee28, FUTEX_WAKE_PRIVATE, 1) = 0
2615 13:04:53.249190 getrusage(RUSAGE_THREAD, {ru_utime={tv_sec=6, tv_usec=131107}, ru_stime={tv_sec=0, tv_usec=512377}, ru_maxrss=1415248, ru_ixrss=0, ru_idrss=0, ru_isrss=0, ru_minflt=3, ru_majflt=7, ru_nswap=0, ru_inblock=904, ru_oublock=0, ru_msgsnd=0, ru_msgrcv=0, ru_nsignals=0, ru_nvcsw=45187, ru_nivcsw=300}) = 0
2615 13:04:53.249267 futex(0x7efc2802ee78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=299998402} <unfinished ...>
2992 13:04:53.249346 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.249374 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.249416 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9999076}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.259600 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.259669 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998583}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.269862 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.269930 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998318} <unfinished ...>
2951 13:04:53.275876 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2951 13:04:53.275954 futex(0x7efc28442a28, FUTEX_WAKE_PRIVATE, 1) = 0
2951 13:04:53.276004 futex(0x7efc28442a78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=49998347} <unfinished ...>
2992 13:04:53.280047 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.280096 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.280141 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998508}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.290333 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.290392 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998348}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.300555 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.300609 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998900}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.310804 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.310878 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998305} <unfinished ...>
2997 13:04:53.318882 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2997 13:04:53.318980 futex(0x7efc298e0128, FUTEX_WAKE_PRIVATE, 1) = 0
2997 13:04:53.319107 futex(0x7efc298e0178, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=99998601} <unfinished ...>
2992 13:04:53.320991 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.321028 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.321071 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9999116} <unfinished ...>
2951 13:04:53.326159 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2951 13:04:53.326225 futex(0x7efc28442a28, FUTEX_WAKE_PRIVATE, 1) = 0
2951 13:04:53.326265 futex(0x7efc28442a78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=49997885} <unfinished ...>
2992 13:04:53.331172 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.331224 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.331276 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998352}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.341419 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.341466 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998473}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.351601 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.351647 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998359}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.361788 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.361834 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998171}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.371984 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.372032 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998375} <unfinished ...>
2951 13:04:53.376376 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2951 13:04:53.376427 futex(0x7efc28442a28, FUTEX_WAKE_PRIVATE, 1) = 0
2951 13:04:53.376465 futex(0x7efc28442a78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=49999429} <unfinished ...>
2992 13:04:53.382147 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.382195 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.382228 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998186}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.392366 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.392410 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998231}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.402554 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.402602 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998401}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.412743 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.412790 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998361} <unfinished ...>
2997 13:04:53.419251 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2997 13:04:53.419300 futex(0x7efc298e0128, FUTEX_WAKE_PRIVATE, 1) = 0
2997 13:04:53.419343 futex(0x7efc298e0178, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=99999061} <unfinished ...>
2992 13:04:53.422887 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.422928 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.422961 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998399} <unfinished ...>
2951 13:04:53.426558 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2951 13:04:53.426595 futex(0x7efc28442a28, FUTEX_WAKE_PRIVATE, 1) = 0
2951 13:04:53.426629 futex(0x7efc28442a78, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=49999301} <unfinished ...>
2992 13:04:53.433070 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.433119 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.433154 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998445}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.443295 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.443341 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998386}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.453473 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.453522 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998338}) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.463666 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.463712 futex(0x7efc2872ddc8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9998111} <unfinished ...>
3002 13:04:53.471612 futex(0x7efc283e7a7c, FUTEX_WAKE_PRIVATE, 1) = 1
3002 13:04:53.471696 futex(0x7efc29998f7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2924 13:04:53.471717 <... restart_syscall resumed> ) = 0
2924 13:04:53.471734 futex(0x7efc283e7a28, FUTEX_WAKE_PRIVATE, 1) = 0
2924 13:04:53.471769 mprotect(0x7efc31817000, 4096, PROT_READ) = 0
2924 13:04:53.471815 mprotect(0x7efc31817000, 4096, PROT_READ|PROT_WRITE) = 0
2924 13:04:53.471849 mprotect(0x7efc31818000, 4096, PROT_NONE) = 0
2924 13:04:53.472428 futex(0x7efc2802c67c, FUTEX_WAKE_PRIVATE, 1) = 1
2614 13:04:53.472463 <... futex resumed> ) = 0
2924 13:04:53.472473 futex(0x7efc283e7a78, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2614 13:04:53.472482 futex(0x7efc2802c628, FUTEX_WAKE_PRIVATE, 1) = 0
2614 13:04:53.472508 futex(0x7efc28028e78, FUTEX_WAKE_PRIVATE, 1) = 1
2612 13:04:53.472530 <... futex resumed> ) = 0
2612 13:04:53.472544 futex(0x7efc28028e28, FUTEX_WAKE_PRIVATE, 1) = 0
2612 13:04:53.472569 futex(0x7efc28027278, FUTEX_WAKE_PRIVATE, 1) = 1
2611 13:04:53.472592 <... futex resumed> ) = 0
2611 13:04:53.472610 futex(0x7efc28027228, FUTEX_WAKE_PRIVATE, 1) = 0
2611 13:04:53.472640 futex(0x7efc2802aa78, FUTEX_WAKE_PRIVATE, 1) = 1
2992 13:04:53.473808 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
2992 13:04:53.473849 futex(0x7efc2872dd78, FUTEX_WAKE_PRIVATE, 1) = 0
2992 13:04:53.473891 futex(0x7efc2872d978, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2612 13:04:53.474207 sched_yield() = 0
2614 13:04:53.474236 sched_yield( <unfinished ...>
2613 13:04:53.474249 <... futex resumed> ) = 0
2614 13:04:53.474260 <... sched_yield resumed> ) = 0
2613 13:04:53.474271 futex(0x7efc2802aa28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2611 13:04:53.474283 sched_yield( <unfinished ...>
2613 13:04:53.474295 <... futex resumed> ) = 0
2611 13:04:53.474306 <... sched_yield resumed> ) = 0
2613 13:04:53.474317 futex(0x7efc283e7a78, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2612 13:04:53.474335 sched_yield() = 0
2614 13:04:53.474365 sched_yield() = 0
2611 13:04:53.474414 sched_yield( <unfinished ...>
2613 13:04:53.474425 <... futex resumed> ) = 1
2611 13:04:53.474436 <... sched_yield resumed> ) = 0
2612 13:04:53.474449 sched_yield( <unfinished ...>
2924 13:04:53.474460 <... futex resumed> ) = 0
2612 13:04:53.474470 <... sched_yield resumed> ) = 0
2924 13:04:53.474480 futex(0x7efc283e7a28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2614 13:04:53.474492 sched_yield( <unfinished ...>
2924 13:04:53.474503 <... futex resumed> ) = 0
2614 13:04:53.474514 <... sched_yield resumed> ) = 0
2924 13:04:53.474525 futex(0x7efc283e7a7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2611 13:04:53.474544 sched_yield( <unfinished ...>
2613 13:04:53.474569 futex(0x7efc283e7a7c, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2612 13:04:53.474581 futex(0x7efc28028e7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2614 13:04:53.474600 futex(0x7efc2802c678, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2924 13:04:53.474610 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
2613 13:04:53.474619 <... futex resumed> ) = 0
2924 13:04:53.474627 futex(0x7efc283e7a28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
2613 13:04:53.474635 futex(0x7efc283e7a28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2924 13:04:53.474642 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
2613 13:04:53.474650 <... futex resumed> ) = 0
2924 13:04:53.474658 futex(0x7efc283e7a28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2613 13:04:53.474666 futex(0x7efc2802aa7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2924 13:04:53.474673 <... futex resumed> ) = 0
2611 13:04:53.474681 <... sched_yield resumed> ) = 0
2924 13:04:53.474689 futex(0x7efc28028e7c, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2611 13:04:53.474697 futex(0x7efc2802727c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2924 13:04:53.474707 <... futex resumed> ) = 1
2612 13:04:53.474715 <... futex resumed> ) = 0
2924 13:04:53.474723 futex(0x7efc283e7a78, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2612 13:04:53.474732 futex(0x7efc28028e28, FUTEX_WAKE_PRIVATE, 1) = 0
2612 13:04:53.474757 futex(0x7efc2802c678, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2614 13:04:53.474772 <... futex resumed> ) = 0
2612 13:04:53.474781 <... futex resumed> ) = 1
2614 13:04:53.474790 futex(0x7efc2802c628, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
2612 13:04:53.474829 futex(0x7efc2802c628, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2614 13:04:53.474838 futex(0x7efc2802c628, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2612 13:04:53.474848 <... futex resumed> ) = 0
2614 13:04:53.474856 <... futex resumed> ) = 0
2612 13:04:53.474865 futex(0x7efc28028e78, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2614 13:04:53.474874 futex(0x7efc2802aa7c, FUTEX_WAKE_PRIVATE, 1) = 1
2613 13:04:53.474895 <... futex resumed> ) = 0
2614 13:04:53.474903 futex(0x7efc2802c67c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2613 13:04:53.474911 futex(0x7efc2802aa28, FUTEX_WAKE_PRIVATE, 1) = 0
2613 13:04:53.474932 futex(0x7efc283e7a78, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2924 13:04:53.474944 <... futex resumed> ) = 0
2613 13:04:53.474952 <... futex resumed> ) = 1
2924 13:04:53.474959 futex(0x7efc283e7a28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
2613 13:04:53.474967 futex(0x7efc283e7a28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2924 13:04:53.474975 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
2613 13:04:53.474983 <... futex resumed> ) = 0
2924 13:04:53.474991 futex(0x7efc283e7a28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
2613 13:04:53.474999 futex(0x7efc2802aa78, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2924 13:04:53.475006 <... futex resumed> ) = 0
2924 13:04:53.475024 futex(0x7efc2802727c, FUTEX_WAKE_PRIVATE, 1) = 1
2611 13:04:53.475043 <... futex resumed> ) = 0
2924 13:04:53.475051 futex(0x7efc283e7a7c, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
2611 13:04:53.475059 futex(0x7efc28027228, FUTEX_WAKE_PRIVATE, 1) = 0
2611 13:04:53.475080 futex(0x7efc28028e78, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>