Ability to write logs from alternative languages

[pyhedgehog]

In JavaScript hooks one can just use console.log to write entry to hook log.
Is it correct, that console.log just writes to stderr stream?
If yes, than why it doesn't works in hooks on other languages?
I've wrote a demo:
Source: https://gist.github.com/pyhedgehog/66cdff7f2d4bcaf792b78515f4e994bf
Test: https://hook.io/pyhedgehog/pytestlog
Result: https://hook.io/pyhedgehog/pytestlog/logs

[Marak]

So this is something that needs to be fixed.

In order to make this work we need to make modifications to the way python process is spawned.

It shouldn't be that complicated, but you have to understand how it's currently working.

see:

https://github.com/bigcompany/hook.io/blob/master/lib/resources/hook/stderr/index.js
https://github.com/bigcompany/hook.io/blob/master/lib/resources/hook/spawnService.js#L92
https://github.com/bigcompany/hook.io/blob/master/lib/resources/hook/spawnService.js#L291

most importantly, we need to modify run-python binary to conform to this kind of API:

https://github.com/bigcompany/hook.io/blob/master/bin/run-hook#L285
https://github.com/bigcompany/hook.io/blob/master/bin/run-hook#L385

Right now it looks like all stdout and stderr are being sent to response for python. We'll want to pipe stderr to logs like it works for JS.

[pyhedgehog]

Thank you. So we have such ability:
https://hook.io/pyhedgehog/testpylog/source
https://hook.io/pyhedgehog/testpylog/logs
All we need - add interface.

[Marak]

@pyhedgehog - Is better we make this integrated as part of run-python binary?

Make nice debug type method for python scripts?

[Marak]

Maybe stderr should auto-encode into JSON message for logging API if no JSON message is found?

That way it would be supported for all languages easily?

[Marak]

( no need to make json object in code )

[pyhedgehog]

I think that this should be installed as logging handler.
stderr should be left intact to allow someone who don't want to use sdk to choose different approach.

[Marak]

That sounds like best practice for python @pyhedgehog

Can you make pull request to run-python and run-python3 binaries to include logging handle?

I think maybe it's easy to do?

[pyhedgehog]

I think such changes should be installed explicitly by micro-service author. Thats what I mean by "allow someone to choose different approach". There are "Explicit is better than implicit" statement in The Zen of Python.
I think that anyone who wants this functionality will write something like:

import hookio
Hook = hookio.install_sdk(Hook)

And anyone who don't want (i.e. wants only datastore), will use:

import hookio
Hook = hookio.install_sdk(Hook, inject_logging=False)
val = Hook.sdk.datastore.get(Hook.params['name'])

or ever:

import hookio
sdk = hookio.createClient()
val = sdk.datastore.get(Hook['params']['name'])

[Marak]

Node.js has console.log method, so for JavaScript, we provide a console.log which pipes to service logs.

You tell me Python has logging handler. Well, we should provide a logging handler which pipes to service logs?

Sugar syntax for logs is expected platform feature.

[pyhedgehog]

Felicitous remark. I will consider it.

[pyhedgehog]

Default functionality of logging module is different than console.log in nodejs.
By default sending to logging does nothing and you must implicitly configure where to send logs.
This can be something as easy as logging.basicConfig() that sends all logs to stderr, but you can precisely select which loggers should be processed by which handlers (log targets) and sent different filters and formatters for them.
Another issue is that alternative languages are supported already a half a year (since 17 Sep 2015) and this will introduce incompatibility (at least theoretically).

[Marak]

Don't worry about incompabitilties, python needs logs.

present solution if you can, or i will try to implement a default logging class for every python service that sends to stderr

[pyhedgehog]

I've prepared piece of code that can be inserted to run-hook-python. But I'm still unsure that it should be enabled by default. Python is about choices and standard logging also has several configurable options.

Here is:

• An example hook: https://hook.io/pyhedgehog/hookiologging236 (will just print "OK")
• Logs of this hook: https://hook.io/pyhedgehog/hookiologging236/logs
• Source of this hook: https://gist.github.com/pyhedgehog/99dae38d1cca86d6fb3ed0d6a4c3cab2

As you can see there are two possible logging modes:

• When format argument is passed to hookioLoggingConfig() it writes formatted strings as a payload.
• When (by default) format is None it writes complete log record data (at least json-able part) and this record can be "revived" on client side:

import hookio, json, logging
logging.basicConfig()
sdk = hookio.createClient()
l1 = sdk.logs.read("pyhedgehog/hookiologging236")
l2 = map(json.loads, l1)
l3 = [logging.makeLogRecord(json.loads(o['data'])) for o in l2]
for o in reversed(l3):
    logging.getLogger(o.name).handle(o)

[pyhedgehog]

I've updated this gist and added sys.excepthook handling - this is standard python feature if you want to process unhandled exceptions. Current hook (HookIOExceptHook class) process exceptions like javascript run-hook - wrap it to {"type":"error", ...} json and additionally wraps as MODULE_NOT_FOUND exceptions pkg_resources.VersionConflict, pkg_resources.DistributionNotFound and ImportError.

This should help implementing python-pip part of hpm.

[Marak]

Nice! Really excited to see Python support improve. Let's group all these changes together and try to push one update which adds logging / packages / sdk.

Thank you so much for your contributions!

👍

[pyhedgehog]

I can create PR just now, but there are several points to discuss.

Logging

Logging has a lot of options to select:

• What level of messaged to log?
• What type of logging to use (json of log record or formatted messages)?
• What format and date format to use if we are using strings?

I think that we should export hookioLoggingConfig() function to hook author and let him decide.
In this case it should be moved to sdk.

Error handling

Error handling has same drawback as logging - it should have options:

• Whether to produce MODULE_NOT_FOUND? Maybe always true.
• Whether to set statusCode to 500? This should be in line with JavaScript.
• Whether to send error text to stdout? In example it's display parameter. Defaults to true if started locally or via gateway.
• Whether to add all traceback to error text? In example it's verbose parameter. Defaults to true if mode is Production.

Same problem hints same solution - export hook class and allow author to use it.

Packages

Sending package requests can be pushed only with error hook support.
Packages support on server side still not implemented.
I'm not sure if ImportError should be parsed too:

• Pro: This will be most often indicator of absent modules. Almost nobody uses pkg_resources interface to check if package is installed.
• Contra: It will be very unreliable about names of packages to install. There are a lot of packages where installable (=pypi) names differ from module names (I.e. after pip install pyOpenSSL you are supposed to do import OpenSSL.

SDK

What will be state of sdk? I'm not sure that I can provide consistent support. Should I pass ownership to bigcompany? Is it possible/practical?

[pyhedgehog]

I think that for python processing requirements.txt file in gist will be much easier to support and use. On hook registration/change command pip install -r requirements.txt (or maybe pip install --upgrade -r requirements.txt) should be emitted.

[Marak]

I am deep into infrastructure refactor this week. Adding 7x more servers

Python support is next on list. I want to review everything you have and will soon.

Thank you so much for the contributions @pyhedgehog

[pyhedgehog]

Right now I'm adding tests to python version of SDK. I have several obstacles: #240, #237. Also I've found several bugs and semi-bugs unrelated to SDK: #242, #243, #244.

[Marak]

All issues noted seem OK to fix this week.

I will first address #240 and #237 in the next few days, that should be easy. Will look into #242 #243 and #244 next.

If you have any other additional issues besides these please let me know this week and I will do my best to address them.

Thank you!

[pyhedgehog]

Reached files API and found #245 and #246. This is not show-stoppers at all, but thoughts only.

[pyhedgehog]

Should I continue to post ideas and found issues? There are unsorted ones. Maybe you can create label like "up-for-grabs" - intended for issues/suggestions that can be implemented by somebody else?

[Marak]

@pyhedgehog - Please feel free to triage the issues.

We've got a new release coming up which is using https://github.com/stackvana/microcule for core spawning API. All python support would be done in microcule library.

Also, many updates to https://github.com/bigcompany/hook.io-sdk

Not ready for testing yet, but will be soon.

[Marak]

@pyhedgehog -

I've got logs working from python services locally by adding only four lines of code to the micro-python binary we have. Will try to deploy soon.

def log( entry ):
   "This writes to the logs"
   sys.stderr.write('{ "type": "log", "payload": { "entry": ' + json.dumps(entry) + '}}\n\n')
   return

This allows the following code in services:

log('hello logs')
log(Hook['params'])

Using this exact same pattern I have also got logs working for lua services.

Unless you can think of a good reason to not do this in Python, I'm going to push forward with this pattern. The key trick here with stderr is that microcule will attempt to parse sys.stderr.write as JSON, and if it fails to parse as JSON, will consider it normal error message and display to client as error.

[pyhedgehog]

I've already referenced more complete implementation of logging bridge: https://gist.github.com/pyhedgehog/99dae38d1cca86d6fb3ed0d6a4c3cab2#file-hookiologging-py-L101

Also I have several questions after last IRC session but you are offline: https://gist.github.com/pyhedgehog/3cbf3f852579ac55f325bbc3e755ffb2

[Marak]

@pyhedgehog -

This is very good. Thank you for your contributions. I understand much better now.

My plan was to just hack a simple global log function for all python services, but now I see how creating this new module importing it is both pythonic and better.

Can we make the errors, logging and WSGI wrapper code go inside here: https://github.com/Stackvana/microcule/blob/master/bin/binaries/micro-python That way it would "just work" for users? Either way, I'd like to get this working soon.

To answer your questions:

Should we change python hook processing (which is currently ugly and un-pythonic).

Yes

If yes - what should we add?
   a. Only add exceptions JSON-ing
   b. (a)+logging init
   c. (b)+WSGI wrapper
   d. (c)+SDK

We'll want all of these items. item d ( SDK ) can be delivered after we ship logging and WSGI wrapper

Should hook.io-sdk-python be transferred to bigcompany authority?

Yes please. I'll add you to the organization. License will be MIT?

[Marak]

Simple logger is now added to lua and python services in microcule

This will be good to at least get some logging working ASAP. I can deploy this very soon until we can do correct pythonic fix.

[pyhedgehog]

I'm digging microcule, but failed to get any log (even from javascript's console.log()!) while running npm test. What should I change in all-languages-tests.js except commenting return in the middle and limiting languages to existing ones?

[Marak]

Try running the examples manually in `master`. See the ReadMe

…

On Tue, Jan 10, 2017 at 8:52 AM, PyHedgehog ***@***.***> wrote: I'm digging microcule, but failed to get any log (even from javascript's console.log()!) while running npm test. What should I change in all-languages-tests.js except commenting return in the middle and limiting languages to existing ones? — You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub <#236 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAERexorALTrYF6Da4WuusvUMeosbztGks5rQ40wgaJpZM4IgnQG> .

[pyhedgehog]

I have preliminary changes. Is there anybody else interested in python hooks?

[Marak]

python WSGI services should be online and deployed now @pyhedgehog

Please take a look if you have a chance.

https://hook.io/examples/python-wsgi
https://hook.io/examples/python-wsgi/source

🎉

[pyhedgehog]

LGFM. Logging works as expected.