orientechnologies / orientdb

OrientDB is the most versatile DBMS supporting Graph, Document, Reactive, Full-Text and Geospatial models in one Multi-Model product. OrientDB can run distributed (Multi-Master), supports SQL, ACID Transactions, Full-Text indexing and Reactive Queries.
https://orientdb.dev
Apache License 2.0
4.72k stars 870 forks source link

OrientEdgeIterator - Found a record (#0:0) that is not an edge #3451

Closed ginojohn closed 9 years ago

ginojohn commented 9 years ago

In our application the following message is printed so many times. It is a very long message with so many numbers in the array.

6:14:02,485 WARNING com.tinkerpop.blueprints.impls.orient.OrientEdgeIterator Found a record (#0:0) that is not an edge. Record: #0:0[49, 52, 124, 32, 124, 35, 48

Attached a program to re-produce the issue.

import java.util.ArrayList;
import java.util.List;

import com.orientechnologies.orient.client.remote.OServerAdmin;
import com.orientechnologies.orient.core.exception.OConcurrentModificationException;
import com.orientechnologies.orient.core.metadata.schema.OClass;
import com.orientechnologies.orient.core.metadata.schema.OType;
import com.orientechnologies.orient.core.sql.OCommandSQL;
import com.tinkerpop.blueprints.Direction;
import com.tinkerpop.blueprints.Edge;
import com.tinkerpop.blueprints.Parameter;
import com.tinkerpop.blueprints.Vertex;
import com.tinkerpop.blueprints.impls.orient.OrientBaseGraph;
import com.tinkerpop.blueprints.impls.orient.OrientEdgeType;
import com.tinkerpop.blueprints.impls.orient.OrientGraph;
import com.tinkerpop.blueprints.impls.orient.OrientGraphFactory;
import com.tinkerpop.blueprints.impls.orient.OrientGraphNoTx;

public final class DatabaseEdgeExceptionTest {

    private String dbName;
    private OrientGraphFactory graphReadFactory;

    public DatabaseEdgeExceptionTest(String dbName) {
        this.dbName = dbName;
        checkAndCreateDatabase(dbName);
    }

    public void runTest() {

        OrientBaseGraph graph = getGraphFactory().getTx();

        Vertex vertex = graph.addVertex("class:Host");
        vertex.setProperty("prop1", "v1-1");
        vertex.setProperty("prop2", "v2-1");
        vertex.setProperty("prop3", "v3-1");

        Vertex vertex1 = graph.addVertex("class:Host");
        vertex1.setProperty("prop1", "v1-2");
        vertex1.setProperty("prop2", "v2-1");
        vertex1.setProperty("prop3", "v3-1");
        graph.commit();
        graph.shutdown();

        Thread th1 = startThread( 2, "prop1");
        Thread th2 = startThread( 3, "prop1");
        Thread th3 = startThread( 4, "prop1");
        try {
            th1.join();
            th2.join();
            th3.join();
        } catch (Exception ex) {
            ex.printStackTrace();
        }

    }

    private Thread startThread(int version, String key) {

        Thread th = new Thread() {
            @Override
            public void run() {
                OrientGraph graph = getGraphFactory().getTx();
                for (int j=0; j < 1000; j++) {
                    for (int i = 1; i <= 100; i ++) {
                        boolean retry = true;
                        while (retry) {
                            try {
                                Vertex vtxx1 = findVertex(graph, "v1-1");
                                Vertex vtxx2 = findVertex(graph, "v1-2");
                                Edge edge1 = vtxx1.addEdge("Connection", vtxx2);
                                edge1.setProperty("linkKey", "key-" + i);
                                List<Edge> deviceEdgeList = new ArrayList<>();
                                Iterable<Vertex> vtxs = graph.command(new OCommandSQL("select from Host")).execute();
                                for (Vertex device : vtxs) {
                                    Iterable<Edge> edges = device.getEdges(Direction.BOTH, "label", "Connection");
                                    for (Edge edge : edges) {
                                        //System.out.println("Selected edge = " + edge + " Link Key =" + edge.getProperty("linkKey"));
                                        deviceEdgeList.add(edge);
                                    }
                                }
                                graph.commit();
                                retry = false;
                            } catch (OConcurrentModificationException ex) {
                                log("Concurrent modification exception retrying.....");
                            } catch (Exception ex) {
                                retry = false;
                                //ex.printStackTrace();
                                //log("Exception skipping....." + ex.getMessage());
                            }
                            List<Edge> deviceEdgeList = new ArrayList<>();
                            Iterable<Vertex> vtxs = graph.command(new OCommandSQL("select from Host")).execute();
                            for (Vertex device : vtxs) {
                                Iterable<Edge> edges = device.getEdges(Direction.BOTH, "label", "Connection");
                                for (Edge edge : edges) {
                                    //System.out.println("Selected edge = " + edge + " Link Key =" + edge.getProperty("linkKey"));
                                    deviceEdgeList.add(edge);
                                }
                            }
                        }
                    }
                }
                graph.shutdown();
            }
        };
        th.start();
        return th;
    }

    private Vertex findVertex(OrientGraph graph, String key) {
        Iterable<Vertex> vtxs = graph.command(new OCommandSQL("select from Host where prop1='" + key + "'")).execute();
        for (Vertex vertex : vtxs) {
            return vertex;
        }
        return null;
    }

    /**
     * @return
     */
    public String getDBURL() {
        return "remote:" + "localhost" + "/" + dbName;
    }

    private OrientGraphFactory getGraphFactory() {
        if (graphReadFactory == null) {
            log("Datastore pool created with size : 10, db location: " + getDBURL());
            graphReadFactory = new OrientGraphFactory(getDBURL()).setupPool(1, 10);
        }
        return graphReadFactory;
    }

    /**
     *
     */
    public void checkAndCreateDatabase(String dbName) {
        try {
            OServerAdmin serverAdmin = new OServerAdmin(getDBURL()).connect("root", "C63447B06BE9A894BFB16031C23796421202D3FE136EC5D617578B025F405343");
            if (serverAdmin.existsDatabase("plocal")) {
                serverAdmin.dropDatabase(dbName);
            }
            log("Database does not exists. New database is created");
            serverAdmin.createDatabase(dbName,"graph", "plocal");
            OrientBaseGraph orientGraph = new OrientGraphNoTx(getDBURL());
            log("Set database CONFLICTSTRATEGY to automerge");
            orientGraph.command(new OCommandSQL("ALTER database CONFLICTSTRATEGY automerge")).execute();
            orientGraph.shutdown();
            serverAdmin.close();
            createDbSchema();
        } catch (Exception ex) {
            log("Failed to create database", ex);
        }
    }

    private void createDbSchema() {
        OrientBaseGraph orientGraph = new OrientGraphNoTx(getDBURL());
        createVertexType(orientGraph, "Host");
        createLinkIndex(orientGraph, "Connection");
        orientGraph.shutdown();
    }

    private void createLinkIndex(OrientBaseGraph orientGraph, String linkName) {
        OrientEdgeType edge = orientGraph.createEdgeType(linkName);
        edge.createProperty("linkKey", OType.STRING);
        orientGraph.createKeyIndex("linkKey", Edge.class, new Parameter<>("class", linkName), new Parameter<>("type", "UNIQUE"));

    }

    private void createVertexType(OrientBaseGraph orientGraph, String className) {
        OClass clazz = orientGraph.getVertexType(className);
        if (clazz == null) {
            log("Creating vertex type - " + className);
            orientGraph.createVertexType(className);
        }
    }

    private void log(String message) {
        System.out.println(message);
    }

    private void log(String message, Throwable th) {
        System.out.println(th.getMessage());
        th.printStackTrace();
    }

    public static void main(String args[]) {
        DatabaseEdgeExceptionTest test = new DatabaseEdgeExceptionTest("edgeexceptiondb");
        test.runTest();
        Runtime.getRuntime().halt(0);
    }

}
ginojohn commented 9 years ago

The edges with #0:0 is growing in the database. Attached screen shot of a vertex with many edges with id #0:0 in the studio.

screen shot 2015-02-07 at 2 12 12 pm

andrii0lomakin commented 9 years ago

Hi Gino :-) I think we will look at this issue during next 3 days. But I suppose we would need to debug it more. So we will provide you few patches.

On Mon, Feb 9, 2015 at 4:08 AM, ginojohn notifications@github.com wrote:

The edges with #0:0 is growing in the database.

— Reply to this email directly or view it on GitHub https://github.com/orientechnologies/orientdb/issues/3451#issuecomment-73447905 .

Best regards, Andrey Lomakin.

tglman commented 9 years ago

hi @ginojohn i ran this test case on 2.0.0 and on the development and i never come across this situation, we may try to catch in wich situation happen and try to log a stacktrace of that, i'll contact you directly.

ginojohn commented 9 years ago

Steps to re-produce the issue

  1. Run the attached program.
  2. Kill the program in between and start again

This will create edges with #0:0 in the database.

import java.util.ArrayList;
import java.util.List;

import com.orientechnologies.orient.client.remote.OServerAdmin;
import com.orientechnologies.orient.core.exception.OConcurrentModificationException;
import com.orientechnologies.orient.core.metadata.schema.OClass;
import com.orientechnologies.orient.core.metadata.schema.OType;
import com.orientechnologies.orient.core.sql.OCommandSQL;
import com.tinkerpop.blueprints.Direction;
import com.tinkerpop.blueprints.Edge;
import com.tinkerpop.blueprints.Parameter;
import com.tinkerpop.blueprints.Vertex;
import com.tinkerpop.blueprints.impls.orient.OrientBaseGraph;
import com.tinkerpop.blueprints.impls.orient.OrientEdgeType;
import com.tinkerpop.blueprints.impls.orient.OrientGraph;
import com.tinkerpop.blueprints.impls.orient.OrientGraphFactory;
import com.tinkerpop.blueprints.impls.orient.OrientGraphNoTx;

public final class DatabaseEdgeExceptionTest  {

    private String dbName;
    private OrientGraphFactory graphReadFactory;

    public DatabaseEdgeExceptionTest(String dbName) {
        this.dbName = dbName;
        checkAndCreateDatabase(dbName);
    }

    public void runTest() {

        OrientBaseGraph graph = getGraphFactory().getTx();

        Vertex vertex = graph.addVertex("class:Host");
        vertex.setProperty("prop1", "v1-1");
        vertex.setProperty("prop2", "v2-1");
        vertex.setProperty("prop3", "v3-1");

        Vertex vertex1 = graph.addVertex("class:Host");
        vertex1.setProperty("prop1", "v1-2");
        vertex1.setProperty("prop2", "v2-1");
        vertex1.setProperty("prop3", "v3-1");

        Vertex vertex2 = graph.addVertex("class:Host");
        vertex2.setProperty("prop1", "v1-3");
        vertex2.setProperty("prop2", "v2-1");
        vertex2.setProperty("prop3", "v3-1");

        graph.commit();
        graph.shutdown();

        Thread th1 = startThread("v1-1", "v1-2");
        Thread th11 = startThread("v1-2", "v1-1");
        Thread th2 = startThread("v1-2", "v1-3");
        Thread th3 = startThread("v1-3", "v1-1");
        Thread th4 = startThread("v1-1", "v1-3");
        try {
            th1.join();
            th2.join();
            th3.join();
            th4.join();
            th11.join();
        } catch (Exception ex) {
            ex.printStackTrace();
        }

    }

    private Thread startThread(String key1, String key2) {

        Thread th = new Thread() {
            @Override
            public void run() {
                OrientGraph graph = getGraphFactory().getTx();
                for (int j=0; j < 1000; j++) {
                    boolean retry = true;
                    while (retry) {
                        try {
                            Vertex vtxx1 = findVertex(graph, key1);
                            Iterable<Edge> edges = vtxx1.getEdges(Direction.IN, "label", "Connection");
                            //LOGGER.debug("### Removing link edges for {}", nodeAndEdge.getClassName());
                            for (Edge edge : edges) {
                                graph.removeEdge(edge);
                                graph.commit();
                            }
                            retry = false;
                        } catch (OConcurrentModificationException ex) {
                            retry = true;
                        } catch (Exception ex) {
                            retry = false;
                            ex.printStackTrace();
                        }
                    }
                    graph.commit();

                    for (int i = 1; i <= 100; i ++) {
                        retry = true;
                        while (retry) {
                            try {
                                Vertex vtxx1 = findVertex(graph, key1);
                                Vertex vtxx2 = findVertex(graph, key2);
                                Edge edge1 = vtxx1.addEdge("Connection", vtxx2);
                                edge1.setProperty("linkKey", "key-" + i);
                                List<Edge> deviceEdgeList = new ArrayList<>();
                                graph.commit();
                                Iterable<Vertex> vtxs = graph.command(new OCommandSQL("select from Host")).execute();
                                for (Vertex device : vtxs) {
                                    Iterable<Edge> edges = device.getEdges(Direction.BOTH, "label", "Connection");
                                    for (Edge edge : edges) {
                                        //System.out.println("Selected edge = " + edge + " Link Key =" + edge.getProperty("linkKey"));
                                        deviceEdgeList.add(edge);
                                    }
                                }
                                retry = false;
                            } catch (OConcurrentModificationException ex) {
                                //log("Concurrent modification exception retrying.....");
                            } catch (Exception ex) {
                                retry = false;
                                //ex.printStackTrace();
                                //log("Exception skipping....." + ex.getMessage());
                            }
                            //List<Edge> deviceEdgeList = new ArrayList<>();
                            //Iterable<Vertex> vtxs = graph.command(new OCommandSQL("select from Host")).execute();
                            //for (Vertex device : vtxs) {
                            //  Iterable<Edge> edges = device.getEdges(Direction.BOTH, "label", "Connection");
                            //for (Edge edge : edges) {
                            //System.out.println("Selected edge = " + edge + " Link Key =" + edge.getProperty("linkKey"));
                            //  deviceEdgeList.add(edge);
                            //}
                            //}
                            graph.commit();
                        }
                    }
                }
                graph.shutdown();
            }
        };
        th.start();
        return th;
    }

    private Vertex findVertex(OrientGraph graph, String key) {
        Iterable<Vertex> vtxs = graph.command(new OCommandSQL("select from Host where prop1='" + key + "'")).execute();
        for (Vertex vertex : vtxs) {
            return vertex;
        }
        return null;
    }

    /**
     * @return
     */
    public String getDBURL() {
        return "remote:" + "localhost" + "/" + dbName;
    }

    private OrientGraphFactory getGraphFactory() {
        if (graphReadFactory == null) {
            log("Datastore pool created with size : 10, db location: " + getDBURL());
            graphReadFactory = new OrientGraphFactory(getDBURL()).setupPool(1, 10);
        }
        return graphReadFactory;
    }

    /**
     *
     */
    public void checkAndCreateDatabase(String dbName) {
        try {
            OServerAdmin serverAdmin = new OServerAdmin(getDBURL()).connect("root", "C63447B06BE9A894BFB16031C23796421202D3FE136EC5D617578B025F405343");
            if (!serverAdmin.existsDatabase("plocal")) {
                log("Database does not exists. New database is created");
                serverAdmin.createDatabase(dbName,"graph", "plocal");
                OrientBaseGraph orientGraph = new OrientGraphNoTx(getDBURL());
                log("Set database CONFLICTSTRATEGY to automerge");
                orientGraph.command(new OCommandSQL("ALTER database CONFLICTSTRATEGY automerge")).execute();
                orientGraph.shutdown();
                serverAdmin.close();
                createDbSchema();
            } else {
                log ("Database already exists.");
            }
        } catch (Exception ex) {
            log("Failed to create database", ex);
        }
    }

    private void createDbSchema() {
        OrientBaseGraph orientGraph = new OrientGraphNoTx(getDBURL());
        createVertexType(orientGraph, "Host");
        createLinkIndex(orientGraph, "Connection");
        orientGraph.shutdown();
    }

    private void createLinkIndex(OrientBaseGraph orientGraph, String linkName) {
        OrientEdgeType edge = orientGraph.createEdgeType(linkName);
        edge.createProperty("linkKey", OType.STRING);
        orientGraph.createKeyIndex("linkKey", Edge.class, new Parameter<>("class", linkName), new Parameter<>("type", "UNIQUE"));

    }

    private void createVertexType(OrientBaseGraph orientGraph, String className) {
        OClass clazz = orientGraph.getVertexType(className);
        if (clazz == null) {
            log("Creating vertex type - " + className);
            orientGraph.createVertexType(className);
        }
    }

    private void log(String message) {
        System.out.println(message);
    }

    private void log(String message, Throwable th) {
        System.out.println(th.getMessage());
        th.printStackTrace();
    }

    public static void main(String args[]) {
        DatabaseEdgeExceptionTest test = new DatabaseEdgeExceptionTest("edgeexceptiondb");
        test.runTest();
        Runtime.getRuntime().halt(0);
    }

}
andrii0lomakin commented 9 years ago

Hi Gino, In such case feature which we discussed, I mean new wal should fix both problems, I mean:

  1. Record #rid is null.
  2. 0:0 edge.

But I have some doubts. I mean do you produce #0:0 edges in such way ? I mean by killing app ?

On Wed, Feb 11, 2015 at 11:21 AM, ginojohn notifications@github.com wrote:

Steps to re-produce the issue

  1. Run the attached program.
  2. Kill the program in between and start again

This will create edges with #0:0 in the database.

Best regards, Andrey Lomakin.

ginojohn commented 9 years ago

The database server is running and it is never killed. Only client that access the server is terminated. I think the terminating a remote client should not result in bad data in the server.

The issue is also observed when the application server (database client) have proper shutdown.

Also if there is a client application shutdown, crash or any improper shutdown of the application will result in edges with #0:0 records in the database. After that any edge query starts giving ' Found a record (#0:0)' messages in the log file. which slows down the query and fills the log file. I mentioned kill the client process to easily re-produce the issue.

We start seeing this issue in the development setup more often because of lot of time application directly terminated in the eclipse.

tglman commented 9 years ago

Hi @ginojohn,

Debugging your test case, i was able to reproduce the issue, and was quite clear that the problem was caused by a wal issue that is going to be solved by the work is doing @laa on the wal, we should have that ready in few days, i will run your test case un the new implementation when is done to double check that everything is fixed.

i don't have a valid work around right now, so i think is better wait the whole fix.

tglman commented 9 years ago

Hi all, finally i found the main reason and i fixed this, is in 2.0.4-hotfix branch if you can give it a try so we can verify that is fixed also in your case, by the way i fixed tnks your test case.