Cannot run cocaine on a local machine

[rshkarin]

I have installed cocaine and cocaine-tools, and tried to install the example ( https://github.com/cocaine/cocaine-framework-python/wiki/Echo-application-example ). When I run cocaine-runtime as non-daemon with the following configuration file ( other sections are the same as in /cocaine-core/debian/cocaine-runtime.conf ):

   "network": {
        "pinned": { "locator": 7800 }
    },
   "services": {
        "locator": {
            "type": "locator",
            "port": "7800"
        },
        "logging": {
            "type": "logging",
            "args": {
                "backend": "core"
            }
        },
        "storage": {
            "type": "storage",
            "args": {
                "backend": "core"
            }
        }
    }

It seems that it works:

Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      -
tcp6       0      0 :::22                   :::*                    LISTEN      -
tcp6       0      0 :::7800                 :::*                    LISTEN      21732/cocaine-runti
tcp6       0      0 :::36090                :::*                    LISTEN      -
tcp6       0      0 :::40411                :::*                    LISTEN      21732/cocaine-runti
tcp6       0      0 :::56640                :::*                    LISTEN      21732/cocaine-runti
tcp6       0      0 :::41091                :::*                    LISTEN      -
tcp6       0      0 :::10053                :::*                    LISTEN      -
udp        0      0 0.0.0.0:68              0.0.0.0:*                           -
udp        0      0 0.0.0.0:10053           0.0.0.0:*                           -
udp        0      0 0.0.0.0:49628           0.0.0.0:*                           -
udp6       0      0 :::20488                :::*                                -

On the other session, I run cocaine-tools and try to upload example app as it is proposed in docs, and after execution of cocaine-tool profile upload, it stucks, to execute next command I need terminate current cocaine-tools process. Moreover, no feedback from cocaine-runtime.

rshkarin@astor-077-jmj:~/co-ex/app$ cocaine-tool profile upload --name EchoProfile --profile=profile.json --debug=all --port=7800
[2015-08-20 12:30:20,911] cocaine.asio.service: DEBUG   : Connecting to the service "locator", candidates: [(10, 1, 6, '', ('::1', 7800, 0, 0)), (2, 1, 6, '', ('127.0.0.1', 7800))]
[2015-08-20 12:30:20,911] cocaine.asio.service: DEBUG   :  - connecting to "6 ('::1', 7800, 0, 0)"
[2015-08-20 12:30:20,911] cocaine.asio.service: DEBUG   :  - success

^C[2015-08-20 12:38:44,885] cocaine.tools: ERROR   : Terminated by user

Could you please advise what I do wrong, and how to configure it properly?
Thanks!

[noxiouz]

Hi,
could you provide me some information about version of components?

[rshkarin]

Hi,

cocaine-runtime 0.12.3
asio 1.10.4
blackhole 0.5.0-2
rapidjson 0.11

cocaine 0.11.1.12 (from pip)

cocaine-tools 0.11.7.5 (from pip)
opster 4.1
tornado 4.2.1

[noxiouz]

First of all cocaine-tools < 12 doesn't work with cocaine > 12 :) you could install it directly from master branch github.com/cocaine/cocaine-tools. When it comes to cocaine-runtime do you build it from source?

[rshkarin]

Oh, thank you, I will try :).
Yes, I built cocaine-runtime from github's sources.

[rshkarin]

Now, it seems works, at least cocaine-tools didn't stuck.
But, when I try to upload app, it claims error in service "locator" - service is not available [1], maybe, my configuration file is wrong, could you check it?

I have tried to follow the docs, step-by-step, but it doesn't work correctly.

{
    "version": 3,
    "logging": {
        "core" : {
            "loggers": [
                {
                    "formatter": {
                        "type": "string",
                        "pattern": "[%(timestamp)s] [%(severity)s]: %(message)s %(...:[:])s"
                    },
                    "sink": {
                        "type": "syslog",
                        "identity": "cocaine"
                    }
                }
            ],
            "timestamp": "%Y-%m-%d %H:%M:%S.%f",
            "verbosity": "info"
        }
    },
    "network": {
        "pinned": {
            "locator": 10099
        }
    },
    "paths": {
        "plugins": "/usr/lib/cocaine",
        "runtime": "/var/run/cocaine"
    },
    "services": {
        "locator": {
            "type": "locator",
            "args": {
                "gateway": {
                    "type": "adhoc"
                }
            }
        },
        "logging": {
            "type": "logging",
            "args": {
                "backend": "core"
            }
        },
        "storage": {
            "type": "storage",
            "args": {
                "backend": "core"
            }
        }
    },
    "storages": {
        "core": {
            "type": "files",
            "args": {
                "path": "/var/lib/cocaine"
            }
        },
        "cache": {
            "type": "files",
            "args": {
                "path": "/var/cache/cocaine"
            }
        }
    }
}

Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      -
tcp6       0      0 :::42288                :::*                    LISTEN      25090/cocaine-runti
tcp6       0      0 :::10099                :::*                    LISTEN      25090/cocaine-runti
tcp6       0      0 :::22                   :::*                    LISTEN      -
tcp6       0      0 :::36090                :::*                    LISTEN      -
tcp6       0      0 :::42207                :::*                    LISTEN      25090/cocaine-runti
tcp6       0      0 :::41091                :::*                    LISTEN      -
tcp6       0      0 :::10053                :::*                    LISTEN      -
udp        0      0 0.0.0.0:68              0.0.0.0:*                           -
udp        0      0 0.0.0.0:10053           0.0.0.0:*                           -
udp        0      0 0.0.0.0:49628           0.0.0.0:*                           -
udp6       0      0 :::20488                :::*                                -

From cocaine-tools:

Uploading package - looks good:

rshkarin@astor-077-jmj:~/co-ex/app$ cocaine-tool app upload --name Echo --manifest=manifest.json --package=echo.tar.gz --debug=all --port=10099
[2015-08-20 17:01:35,344] dispatcher cocaine.tools:244 INFO    : Setting timeout to the 120.000000s
[2015-08-20 17:01:35,345] __init__ cocaine.tools:61 DEBUG   : Loading content from file ...
[  OK  ] Loading manifest
[  OK  ] Reading package "echo.tar.gz"
[2015-08-20 17:01:35,346] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('apps', 'Echo', '\xda\x01P\x1f\x8b\x08\x00\xd3\x9f\xd5U\x00\x03\xed\xd2Ao\x820\x14\x07p\xce|\x8a7w\x00\x92\xa5"\x13ML\xf6\x01\x96l\xa7\x1d<#<\xb1QZ\xd6\x82\xc6\x18\xbf\xfb*\xe22\x0f\xcbNfY\xf6\xff]\x9a\xd7\xfei_S8_iQ\xef\xbd[\x8a\x9d\xe9d|\x1aG\xd34\xfe:v\xd2$\xf6FI:I\x1f\xdd\xf4\xd8\xcd\x8f\x92I\x {}
[2015-08-20 17:01:35,346] service cocaine.baseservice:54 DEBUG   : checking if service connected
[2015-08-20 17:01:35,346] service cocaine.baseservice:59 INFO    : resolving ...
[2015-08-20 17:01:35,346] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('storage',) {}
[2015-08-20 17:01:35,347] baseservice cocaine.baseservice:91 INFO    : acquiring the connection lock
[2015-08-20 17:01:35,347] baseservice cocaine.baseservice:100 INFO    : trying localhost:10099 to establish connection locator
[2015-08-20 17:01:35,348] baseservice cocaine.baseservice:110 INFO    : connection has been established successfully 1.251ms
[2015-08-20 17:01:35,348] baseservice cocaine.baseservice:163 DEBUG   : {0: ['resolve', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['connect', {}, {0: ['write', None], 1: ['error', {}], 2: ['close', {}]}], 2: ['refresh', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['cluster', {}, {0: ['value', {}], 1: ['error', {}]}], 4: ['publish', {0: ['discard', {}]}, {0: ['value', {}], 1: ['error', {}]}], 5: ['routing', {}, {0: ['write', None], 1: ['error', {}], 2: ['close', {}]}]}
[2015-08-20 17:01:35,348] baseservice cocaine.baseservice:166 DEBUG   : method `resolve` has been found in API map
[2015-08-20 17:01:35,349] baseservice cocaine.baseservice:168 DEBUG   : sending message: [1, 0, ('storage',)]
[2015-08-20 17:01:35,349] baseservice cocaine.baseservice:173 DEBUG   : RX TREE {0: ['value', {}], 1: ['error', {}]}
[2015-08-20 17:01:35,349] baseservice cocaine.baseservice:174 DEBUG   : TX TREE {}
[2015-08-20 17:01:35,349] baseservice cocaine.baseservice:135 DEBUG   : read ▒▒▒▒▒127.0.1.1ͥ0▒▒▒read▒▒▒▒value▒▒▒error▒▒▒write▒▒▒▒value▒▒▒error▒▒▒remove▒▒▒▒value▒▒▒error▒▒▒find▒▒▒▒value▒▒▒error▒▒▒P▒Q▒R
[2015-08-20 17:01:35,350] baseservice cocaine.baseservice:138 DEBUG   : unpacked: [1, 0, [[['127.0.1.1', 42288]], 1, {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}], [80, 81, 82]]
[2015-08-20 17:01:35,350] baseservice cocaine.baseservice:141 DEBUG   : 1, 0, [[['127.0.1.1', 42288]], 1, {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}]
[2015-08-20 17:01:35,350] channel cocaine.channel:137 DEBUG   : dispatch ['value', {}] [[['127.0.1.1', 42288]], 1, {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}]
[2015-08-20 17:01:35,350] channel cocaine.channel:142 DEBUG   : name `value` rx `{}`
[2015-08-20 17:01:35,350] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:01:35,351] service cocaine.baseservice:75 INFO    : successfully resolved [['127.0.1.1', 42288]]
[2015-08-20 17:01:35,351] service cocaine.baseservice:76 DEBUG   : api: {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}
[2015-08-20 17:01:35,351] baseservice cocaine.baseservice:91 INFO    : acquiring the connection lock
[2015-08-20 17:01:35,351] baseservice cocaine.baseservice:100 INFO    : trying 127.0.1.1:42288 to establish connection storage
[2015-08-20 17:01:35,351] baseservice cocaine.baseservice:131 DEBUG   : pipe has been closed ('',) locator
[2015-08-20 17:01:35,352] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:01:35,352] baseservice cocaine.baseservice:110 INFO    : connection has been established successfully 0.805ms
[2015-08-20 17:01:35,352] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:01:35,352] baseservice cocaine.baseservice:163 DEBUG   : {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}
[2015-08-20 17:01:35,352] baseservice cocaine.baseservice:166 DEBUG   : method `write` has been found in API map
[2015-08-20 17:01:35,352] baseservice cocaine.baseservice:168 DEBUG   : sending message: [1, 1, ('apps', 'Echo', '\xda\x01P\x1f\x8b\x08\x00\xd3\x9f\xd5U\x00\x03\xed\xd2Ao\x820\x14\x07p\xce|\x8a7w\x00\x92\xa5"\x13ML\xf6\x01\x96l\xa7\x1d<#<\xb1QZ\xd6\x82\xc6\x18\xbf\xfb*\xe22\x0f\xcbNfY\xf6\xff]\x9a\xd7\xfei_S8_iQ\xef\xbd[\x8a\x9d\xe9d|\x1aG\xd34\xfe:v\xd2$\xf6FI:I\x1f\xdd\xf4\xd8\xcd\x8f
[2015-08-20 17:01:35,353] baseservice cocaine.baseservice:173 DEBUG   : RX TREE {0: ['value', {}], 1: ['error', {}]}
[2015-08-20 17:01:35,353] baseservice cocaine.baseservice:174 DEBUG   : TX TREE {}
[2015-08-20 17:01:35,353] baseservice cocaine.baseservice:135 DEBUG   : read ▒▒▒▒P▒Q▒R
[2015-08-20 17:01:35,353] baseservice cocaine.baseservice:138 DEBUG   : unpacked: [1, 0, [], [80, 81, 82]]
[2015-08-20 17:01:35,353] baseservice cocaine.baseservice:141 DEBUG   : 1, 0, []
[2015-08-20 17:01:35,353] channel cocaine.channel:137 DEBUG   : dispatch ['value', {}] []
[2015-08-20 17:01:35,354] channel cocaine.channel:142 DEBUG   : name `value` rx `{}`
[  OK  ] Uploading application "Echo"
[2015-08-20 17:01:35,354] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('manifests', 'Echo', '\x81\xa5slave\xda\x00 /home/rshkarin/co-ex/app/echo.py', ('app',)) {}
[2015-08-20 17:01:35,354] service cocaine.baseservice:54 DEBUG   : checking if service connected
[2015-08-20 17:01:35,354] service cocaine.baseservice:56 DEBUG   : already connected
[2015-08-20 17:01:35,354] baseservice cocaine.baseservice:163 DEBUG   : {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}
[2015-08-20 17:01:35,354] baseservice cocaine.baseservice:166 DEBUG   : method `write` has been found in API map
[2015-08-20 17:01:35,355] baseservice cocaine.baseservice:168 DEBUG   : sending message: [2, 1, ('manifests', 'Echo', '\x81\xa5slave\xda\x00 /home/rshkarin/co-ex/app/echo.py', ('app',))]
[2015-08-20 17:01:35,355] baseservice cocaine.baseservice:173 DEBUG   : RX TREE {0: ['value', {}], 1: ['error', {}]}
[2015-08-20 17:01:35,355] baseservice cocaine.baseservice:174 DEBUG   : TX TREE {}
[2015-08-20 17:01:35,355] baseservice cocaine.baseservice:135 DEBUG   : read ▒▒▒▒P▒Q▒R
[2015-08-20 17:01:35,355] baseservice cocaine.baseservice:138 DEBUG   : unpacked: [2, 0, [], [80, 81, 82]]
[2015-08-20 17:01:35,355] baseservice cocaine.baseservice:141 DEBUG   : 2, 0, []
[2015-08-20 17:01:35,356] channel cocaine.channel:137 DEBUG   : dispatch ['value', {}] []
[2015-08-20 17:01:35,356] channel cocaine.channel:142 DEBUG   : name `value` rx `{}`
[  OK  ] Uploading manifest
[2015-08-20 17:01:35,356] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called storage

Uploading profile:

rshkarin@astor-077-jmj:~/co-ex/app$ cocaine-tool profile upload --name EchoProfile --profile=profile.json --port=10099 --debug=all
[2015-08-20 17:03:12,407] __init__ cocaine.tools:61 DEBUG   : Loading content from file ...
[  OK  ] Loading profile
[2015-08-20 17:03:12,408] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('profiles', 'EchoProfile', '\x81\xaapool-limit\x04', ('profile',)) {                 }
[2015-08-20 17:03:12,408] service cocaine.baseservice:54 DEBUG   : checking if service connected
[2015-08-20 17:03:12,408] service cocaine.baseservice:59 INFO    : resolving ...
[2015-08-20 17:03:12,408] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('storage',) {}
[2015-08-20 17:03:12,408] baseservice cocaine.baseservice:91 INFO    : acquiring the connection lock
[2015-08-20 17:03:12,408] baseservice cocaine.baseservice:100 INFO    : trying localhost:10099 to establish connection locator
[2015-08-20 17:03:12,410] baseservice cocaine.baseservice:110 INFO    : connection has been established successfully 1.408ms
[2015-08-20 17:03:12,410] baseservice cocaine.baseservice:163 DEBUG   : {0: ['resolve', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['connect', {}, {0: ['write', N                 one], 1: ['error', {}], 2: ['close', {}]}], 2: ['refresh', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['cluster', {}, {0: ['value', {}], 1: ['error', {}]}], 4: ['                 publish', {0: ['discard', {}]}, {0: ['value', {}], 1: ['error', {}]}], 5: ['routing', {}, {0: ['write', None], 1: ['error', {}], 2: ['close', {}]}]}
[2015-08-20 17:03:12,410] baseservice cocaine.baseservice:166 DEBUG   : method `resolve` has been found in API map
[2015-08-20 17:03:12,410] baseservice cocaine.baseservice:168 DEBUG   : sending message: [1, 0, ('storage',)]
[2015-08-20 17:03:12,411] baseservice cocaine.baseservice:173 DEBUG   : RX TREE {0: ['value', {}], 1: ['error', {}]}
[2015-08-20 17:03:12,411] baseservice cocaine.baseservice:174 DEBUG   : TX TREE {}
[2015-08-20 17:03:12,411] baseservice cocaine.baseservice:135 DEBUG   : read ▒▒▒▒▒127.0.1.1ͥ0▒▒▒read▒▒▒▒value▒▒▒error▒▒▒write▒▒▒▒value▒▒▒error▒▒▒remove▒▒▒▒value▒▒▒err                 or▒▒▒find▒▒▒▒value▒▒▒error▒▒▒P▒Q▒R
[2015-08-20 17:03:12,412] baseservice cocaine.baseservice:138 DEBUG   : unpacked: [1, 0, [[['127.0.1.1', 42288]], 1, {0: ['read', {}, {0: ['value', {}], 1: ['error',                  {}]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['erro                 r', {}]}]}], [80, 81, 82]]
[2015-08-20 17:03:12,412] baseservice cocaine.baseservice:141 DEBUG   : 1, 0, [[['127.0.1.1', 42288]], 1, {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1:                  ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}]
[2015-08-20 17:03:12,412] channel cocaine.channel:137 DEBUG   : dispatch ['value', {}] [[['127.0.1.1', 42288]], 1, {0: ['read', {}, {0: ['value', {}], 1: ['error', {                 }]}], 1: ['write', {}, {0: ['value', {}], 1: ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error'                 , {}]}]}]
[2015-08-20 17:03:12,412] channel cocaine.channel:142 DEBUG   : name `value` rx `{}`
[2015-08-20 17:03:12,413] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:03:12,413] service cocaine.baseservice:75 INFO    : successfully resolved [['127.0.1.1', 42288]]
[2015-08-20 17:03:12,413] service cocaine.baseservice:76 DEBUG   : api: {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1                 : ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}
[2015-08-20 17:03:12,413] baseservice cocaine.baseservice:91 INFO    : acquiring the connection lock
[2015-08-20 17:03:12,413] baseservice cocaine.baseservice:100 INFO    : trying 127.0.1.1:42288 to establish connection storage
[2015-08-20 17:03:12,414] baseservice cocaine.baseservice:131 DEBUG   : pipe has been closed ('',) locator
[2015-08-20 17:03:12,414] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:03:12,414] baseservice cocaine.baseservice:110 INFO    : connection has been established successfully 1.010ms
[2015-08-20 17:03:12,414] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:03:12,415] baseservice cocaine.baseservice:163 DEBUG   : {0: ['read', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['write', {}, {0: ['value', {}], 1                 : ['error', {}]}], 2: ['remove', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['find', {}, {0: ['value', {}], 1: ['error', {}]}]}
[2015-08-20 17:03:12,415] baseservice cocaine.baseservice:166 DEBUG   : method `write` has been found in API map
[2015-08-20 17:03:12,415] baseservice cocaine.baseservice:168 DEBUG   : sending message: [1, 1, ('profiles', 'EchoProfile', '\x81\xaapool-limit\x04', ('profile',))]
[2015-08-20 17:03:12,415] baseservice cocaine.baseservice:173 DEBUG   : RX TREE {0: ['value', {}], 1: ['error', {}]}
[2015-08-20 17:03:12,416] baseservice cocaine.baseservice:174 DEBUG   : TX TREE {}
[2015-08-20 17:03:12,416] baseservice cocaine.baseservice:135 DEBUG   : read ▒▒▒▒P▒Q▒R
[2015-08-20 17:03:12,416] baseservice cocaine.baseservice:138 DEBUG   : unpacked: [1, 0, [], [80, 81, 82]]
[2015-08-20 17:03:12,416] baseservice cocaine.baseservice:141 DEBUG   : 1, 0, []
[2015-08-20 17:03:12,416] channel cocaine.channel:137 DEBUG   : dispatch ['value', {}] []
[2015-08-20 17:03:12,416] channel cocaine.channel:142 DEBUG   : name `value` rx `{}`
[  OK  ] Uploading "EchoProfile"
[2015-08-20 17:03:12,417] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called storage

Starting app:

rshkarin@astor-077-jmj:~/co-ex/app$ cocaine-tool app start --name Echo --profile=EchoProfile --port=10099 --debug=all
[2015-08-20 17:05:25,094] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('Echo', 'EchoProfile') {}
[2015-08-20 17:05:25,095] service cocaine.baseservice:54 DEBUG   : checking if service connected
[2015-08-20 17:05:25,095] service cocaine.baseservice:59 INFO    : resolving ...
[2015-08-20 17:05:25,095] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('node',) {}
[2015-08-20 17:05:25,095] baseservice cocaine.baseservice:91 INFO    : acquiring the connection lock
[2015-08-20 17:05:25,095] baseservice cocaine.baseservice:100 INFO    : trying localhost:10099 to establish connection locator
[2015-08-20 17:05:25,097] baseservice cocaine.baseservice:110 INFO    : connection has been established successfully 1.380ms
[2015-08-20 17:05:25,097] baseservice cocaine.baseservice:163 DEBUG   : {0: ['resolve', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['connect', {}, {0: ['write', None], 1: ['error', {}], 2: ['close', {}]}], 2: ['refresh', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['cluster', {}, {0: ['value', {}], 1: ['error', {}]}], 4: ['publish', {0: ['discard', {}]}, {0: ['value', {}], 1: ['error', {}]}], 5: ['routing', {}, {0: ['write', None], 1: ['error', {}], 2: ['close', {}]}]}
[2015-08-20 17:05:25,097] baseservice cocaine.baseservice:166 DEBUG   : method `resolve` has been found in API map
[2015-08-20 17:05:25,097] baseservice cocaine.baseservice:168 DEBUG   : sending message: [1, 0, ('node',)]
[2015-08-20 17:05:25,098] baseservice cocaine.baseservice:173 DEBUG   : RX TREE {0: ['value', {}], 1: ['error', {}]}
[2015-08-20 17:05:25,098] baseservice cocaine.baseservice:174 DEBUG   : TX TREE {}
[2015-08-20 17:05:25,098] baseservice cocaine.baseservice:135 DEBUG   : read ▒▒▒
▒service is not available▒▒P▒Q▒R
[2015-08-20 17:05:25,098] baseservice cocaine.baseservice:138 DEBUG   : unpacked: [1, 1, [[10, 1], 'service is not available'], [80, 81, 82]]
[2015-08-20 17:05:25,099] baseservice cocaine.baseservice:141 DEBUG   : 1, 1, [[10, 1], 'service is not available']
[2015-08-20 17:05:25,099] channel cocaine.channel:137 DEBUG   : dispatch ['error', {}] [[10, 1], 'service is not available']
[2015-08-20 17:05:25,099] channel cocaine.channel:142 DEBUG   : name `error` rx `{}`
[2015-08-20 17:05:25,099] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:05:25,100] baseservice cocaine.baseservice:131 DEBUG   : pipe has been closed ('',) locator
[2015-08-20 17:05:25,100] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:05:25,101] cli cocaine.tools:52 ERROR   : error in service "locator" - service is not available [1]
[2015-08-20 17:05:25,106] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-20 17:05:25,106] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called node

[noxiouz]

Hello again!
I forgot to tell you about some tricks :)
We are inside huge merge right now.
It's better to build the core from https://github.com/3Hren/cocaine-core/tree/nightly
Also you need to build node plugin from https://github.com/cocaine/cocaine-plugins/tree/v0.12-bleeding-edge and install it as all other plugins.
After that, you should change the name of Node service type from "node" to "node::v2":

 "services": {
        "node": {
            "type": "node::v2",
            "args": {
                "runlist": "default"
            }
        },

[rshkarin]

Hi,

I have reinstalled cocaine-core and cocaine-plugins from branches you specified, it works, but I still can't upload/run app.
When I try to run cocaine-runtime as a non-daemon using the following configuration file, it just finishes without any errors/warnings. If I remove node from services section, it starts listening, but in this case the error of error in service locator - service is not available [1] happens.
I have used the minimalistic configuration file proposed in the docs ( https://github.com/cocaine/cocaine-docs/blob/v0.12/doc/server_maintenance/maintenance_server_configuration.md ).

What it could be?

The cocaine-runtime instantly finishes:

rshkarin@astor-077-jmj:~/cocks-v2/co-ex$ cocaine-runtime -c min-conf.conf
[Runtime] Parsing the configuration.
[Runtime] Initializing the logging system, backend: core.
rshkarin@astor-077-jmj:~/cocks-v2/co-ex$

The configuration file:

{
    "version": 3,
    "network": {
        "pinned": { "locator": 11900 }
    },
    "services": {
        "locator": {
            "type": "locator"
        },
        "node": {
            "type": "node::v2",
            "args": {
                "runlist": "default"
            }
        },
        "logging": {
            "type": "logging"
        },
        "storage": {
            "type": "storage"
        }
    },
    "storages": {
        "core": {
            "type": "files",
            "args": {
                "path": "/var/lib/cocaine"
            }
        }
    },
    "logging": {
        "core" : {
            "loggers": [
                {
                    "formatter": {
                        "type": "string",
                        "pattern": "[%(timestamp)s] [%(severity)s]: %(message)s %(...:[:])s"
                    },
                    "sink": {
                        "type": "syslog",
                        "identity": "cocaine"
                    }
                }
            ],
            "timestamp": "%Y-%m-%d %H:%M:%S.%f",
            "verbosity": "info"
        }
    }
}

If remove node from configs, cocaine-runtime starts listening:

rshkarin@astor-077-jmj:~/cocks-v2/co-ex/app$ cocaine-tool info --port=11900 --debug=all
[2015-08-21 17:08:37,305] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called () {}
[2015-08-21 17:08:37,305] service cocaine.baseservice:54 DEBUG   : checking if service connected
[2015-08-21 17:08:37,305] service cocaine.baseservice:59 INFO    : resolving ...
[2015-08-21 17:08:37,306] baseservice cocaine.baseservice:157 DEBUG   : _invoke has been called ('node',) {}
[2015-08-21 17:08:37,306] baseservice cocaine.baseservice:91 INFO    : acquiring the connection lock
[2015-08-21 17:08:37,306] baseservice cocaine.baseservice:100 INFO    : trying localhost:11900 to establish connection locator
[2015-08-21 17:08:37,308] baseservice cocaine.baseservice:110 INFO    : connection has been established successfully 1.731ms
[2015-08-21 17:08:37,308] baseservice cocaine.baseservice:163 DEBUG   : {0: ['resolve', {}, {0: ['value', {}], 1: ['error', {}]}], 1: ['connect', {}, {0: ['write', None], 1: ['error', {}], 2: ['close', {}]}], 2: ['refresh', {}, {0: ['value', {}], 1: ['error', {}]}], 3: ['cluster', {}, {0: ['value', {}], 1: ['error', {}]}], 4: ['publish', {0: ['discard', {}]}, {0: ['value', {}], 1: ['error', {}]}], 5: ['routing', {}, {0: ['write', None], 1: ['error', {}], 2: ['close', {}]}]}
[2015-08-21 17:08:37,308] baseservice cocaine.baseservice:166 DEBUG   : method `resolve` has been found in API map
[2015-08-21 17:08:37,308] baseservice cocaine.baseservice:168 DEBUG   : sending message: [1, 0, ('node',)]
[2015-08-21 17:08:37,309] baseservice cocaine.baseservice:173 DEBUG   : RX TREE {0: ['value', {}], 1: ['error', {}]}
[2015-08-21 17:08:37,309] baseservice cocaine.baseservice:174 DEBUG   : TX TREE {}
[2015-08-21 17:08:37,309] baseservice cocaine.baseservice:135 DEBUG   : read ▒▒▒
▒service is not available▒▒P▒Q▒R
[2015-08-21 17:08:37,310] baseservice cocaine.baseservice:138 DEBUG   : unpacked: [1, 1, [[10, 1], 'service is not available'], [80, 81, 82]]
[2015-08-21 17:08:37,310] baseservice cocaine.baseservice:141 DEBUG   : 1, 1, [[10, 1], 'service is not available']
[2015-08-21 17:08:37,310] channel cocaine.channel:137 DEBUG   : dispatch ['error', {}] [[10, 1], 'service is not available']
[2015-08-21 17:08:37,310] channel cocaine.channel:142 DEBUG   : name `error` rx `{}`
[2015-08-21 17:08:37,311] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-21 17:08:37,311] baseservice cocaine.baseservice:131 DEBUG   : pipe has been closed ('',) locator
[2015-08-21 17:08:37,311] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-21 17:08:37,312] cli cocaine.tools:52 ERROR   : error in service "locator" - service is not available [1]
[2015-08-21 17:08:37,317] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator
[2015-08-21 17:08:37,318] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called node
[2015-08-21 17:08:37,318] baseservice cocaine.baseservice:116 DEBUG   : disconnect has been called locator

Thanks!

[noxiouz]

Could you provide me logs from syslog about cocaine-runtime, please?

[rshkarin]

Here is:

Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.448840] [I]: initializing the server
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.452933] [I]: initializing the core [source: core]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.453125] [E]: unable to load plugins: path '/usr/lib/cocaine' is not valid [source: core]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.453200] [I]: starting 8 execution unit(s) [source: core]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.454635] [I]: starting 4 service(s) [source: core]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.454822] [I]: restricting 1 service(s): locator [source: core, service: locator]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.455014] [I]: exposing service on local endpoint [::]:11900 [source: core, service: locator]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.455472] [I]: exposing service on local endpoint [::]:50404 [source: core, service: logging]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.455731] [E]: unable to initialize service: [1] component is not available [source: core, service: node]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.455867] [I]: exposing service on local endpoint [::]:38358 [source: core, service: storage]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.456090] [E]: emergency core shutdown [source: core]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.456302] [I]: removing service from local endpoint [::]:38358 [source: core, service: storage]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.456451] [I]: removing service from local endpoint [::]:50404 [source: core, service: logging]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.456586] [I]: removing service from local endpoint [::]:11900 [source: core, service: locator]
Aug 21 18:07:13 astor-077-jmj cocaine[19634]: [2015-08-21 16:07:13.457849] [E]: unable to initialize the context - couldn't start 1 service(s): node: Invalid argument.

[noxiouz]

As we can see plugin for service node is not available. Did you install it? If you just buit from source and ran make install it should be inside /usr/local/lib/cocaine instead of /usr/lib/cocaine. So move it or fix the configuration file.

[rshkarin]

Hi,

now, it works, I can see that the app is executing on the node.
Thank you very much for the help!

But, the last thing (I hope), how to send the request to this app and get the response?
I have tried the code provided by the docs.

from cocaine.services import Service


if __name__ == '__main__':
    service = Service('Echo')
    chunk = service.enqueue('doIt', 'SomeMessage').get()
    print('Response received - {0}'.format(chunk))

But, it produce error:

rshkarin@astor-077-jmj:~/cocks-v2/co-ex/app$ python try.py
Traceback (most recent call last):
  File "try.py", line 6, in <module>
    chunk = service.enqueue('doIt', 'SomeMessage').get()
AttributeError: 'Future' object has no attribute 'get'

I have checked the sources of Service, and found out that, probably the way of communication described in the docs is a bit obsoleted.

Could you advise, what I do wrong?

[noxiouz]

There're some changes from v0.11 to v0.12. You installed cocaine-framework-python for 0.12, right?
Just few steps left.
So change from cocaine.logging import Logger in worker from cocaine.logger import Logger in worker code.

#!/usr/bin/env python

from tornado import gen
from tornado.ioloop import IOLoop
from cocaine.services import Service

io = IOLoop.current()
import os

@gen.coroutine
def f():
    # create service
    service = Service("Echo")
    # create new output stream to app with enqueue method
    channel = yield service.enqueue("doIt")
    # send one chunk of data to the app
    yield channel.tx.write("SomeMessage")
    # get one chunk from the app
    res = yield channel.rx.get()
    print res
    channel.tx.close()

io.run_sync(f, timeout=10)

[rshkarin]

Now it works! Thank you! 👍

I have tried on another machine, seems it works, but it can't communicate with the client app, syslog collected the following entries, maybe you know the reason for unable to activate slave?

66914 Aug 22 02:22:58 astor-034-p5j cocaine[27346]: [2015-08-22 00:22:58.312933] [I]: deploying app to "/var/spool/cocaine/Echo" [source: Echo]
66915 Aug 22 02:22:58 astor-034-p5j cocaine[27346]: [2015-08-22 00:22:58.313511] [I]: compression: gzip, size: 302 bytes [source: packaging]
66916 Aug 22 02:22:58 astor-034-p5j cocaine[27346]: [2015-08-22 00:22:58.313923] [I]: extracted 1 file(s) [source: packaging]
66917 Aug 22 02:22:58 astor-034-p5j cocaine[27346]: [2015-08-22 00:22:58.316212] [I]: exposing service on local endpoint [::]:41405 [source: core, service: Echo]
66918 Aug 22 02:22:58 astor-034-p5j cocaine[27346]: [2015-08-22 00:22:58.317302] [I]: exposing service on local endpoint /var/run/cocaine/Echo.27346 [source: core::io, app: Echo/         hostess]
66919 Aug 22 02:23:07 astor-034-p5j cocaine[27346]: [2015-08-22 00:23:07.055397] [I]: enlarging the slaves pool to 1 [source: Echo/overseer]
66920 Aug 22 02:23:12 astor-034-p5j cocaine[27346]: [2015-08-22 00:23:12.060020] [E]: unable to activate slave: timeout [source: Echo/slave, uuid: 9cc86e1d-08f4-4c49-b9d2-                d3a962b3df34]
66921 Aug 22 02:23:12 astor-034-p5j cocaine[27346]: [2015-08-22 00:23:12.061031] [W]: slave has died in silence [source: Echo/slave, uuid: 9cc86e1d-08f4-4c49-b9d2-d3a962b3df34]
66922 Aug 22 02:23:12 astor-034-p5j cocaine[27346]: [2015-08-22 00:23:12.061307] [W]: slave is dropping 0 sessions [source: Echo/slave, uuid: 9cc86e1d-08f4-4c49-b9d2-d3a962b3df34]
66923 Aug 22 02:23:12 astor-034-p5j cocaine[27346]: [2015-08-22 00:23:12.062339] [I]: enlarging the slaves pool to 1 [source: Echo/overseer]

[noxiouz]

I guess a wrong version of framework is installed on the machine, for example.
To investigate it we can change the verbosity of a logger:

"verbosity": "debug"

I'm not sure if your syslog is tuned to not to filter debug messages out. If no messages with [D] appear in syslog after that, we can try to log to a file or stderr:

"sink": {
                        "type": "stream",
                        "identity": "cocaine",
                        "output": "/dev/stderr"
 }

So first of all, check the version of python-framework on the server (astor-034-p5j).
After that cat /var/spoo/cocaine/Echo/__init__.py (I assume you named it __init__.py) to check that the source code is good. If it's not the same as on a server where it works - let me know.

[rshkarin]

Hi! Thank you!

I have managed to install and run it on the another machine, the libs and other stuff were in a mess.

To summarize the steps of installation:

git clone https://github.com/3Hren/cocaine-core.git
cd cocaine-core
git submodule update --init
sudo apt-get install equivs devscripts
sudo mk-build-deps -ir
mkdir build && cd build
cmake -DCMAKE_BUILD_TYPE=RelWithDebInfo -DCMAKE_INSTALL_PREFIX=/usr/local ..
make -j$(grep -c 'processor' /proc/cpuinfo)
sudo make install

git clone https://github.com/cocaine/cocaine-framework-python.git
cd cocaine-framework-python
sudo mk-build-deps -ir
python setup.py install

git clone  https://github.com/cocaine/cocaine-plugins.git
cd cocaine-plugins
git checkout v0.12-bleeding-edge
git submodule update --init
sudo mk-build-deps -ir
sudo apt-get install libcurl4-nss-dev libcurlpp-dev libnl-dev
sudo apt-get install libnl-3-dev
sudo apt-get install libzookeeper-mt-dev
mkdir build && cd build
cmake -DCMAKE_BUILD_TYPE=RelWithDebInfo -DCMAKE_INSTALL_PREFIX=/usr/local ..
ccmake ..
## turn off IPVS, ELASTICSEARCH, URLFETCH
cmake -DCMAKE_BUILD_TYPE=RelWithDebInfo -DCMAKE_INSTALL_PREFIX=/usr/local ..
make
sudo make install

git clone https://github.com/cocaine/cocaine-tools.git
sudo mk-build-deps -ir
python setup.py install

-----
Prepare serv conf, app and service files
-----
sudo mkdir -p /var/run/cocaine
sudo cocaine-runtime -c serv-config.conf

---
chmod u+x echo.py
tar -czf echo.tar.gz echo.py
cocaine-tool app upload --name Echo --manifest=manifest.json --package=echo.tar.gz --port 11900
cocaine-tool profile upload --name EchoProfile --profile=profile.json --port 11900
# IF Cgroup issue: http://stackoverflow.com/questions/27454848/cgroups-sys-fs-cgroup-is-empty-on-ubuntu
cocaine-tool app start --name Echo --profile=EchoProfile --port 11900

---
It might be need to run an application from sudo mode first, and after it will
work well for normal mode.