Add line numbers by dancmeyers · Pull Request #1 · osfameron/fudge

dancmeyers · 2017-08-11T23:58:09Z

Most info is covered in the commit messages. However:

I added the multiple spy/spy-with variants for thread first and last as a convenience. Can remove those and leave just the one call for each if that is preferred, though it would mean anonymous functions when calling in the other context.

Also I noticed after I'd done the spy/spy-with variants commit that my change of the docstring for spy-with in the previous commit had been wrong, but the original from before that was also wrong. The original was a thread-first thread, but the spy-with function arg order meant it was thread-last. I made the thread thread-last in the doc, but of course functions like update don't run in a thread-last context... The latest commit fixes all of that and both docstrings contain a thread I've tested and proved works.

To match all the other tests.

Getting metadata about the file, namespace and line the log function was called from requires the use of macros. So convert the log functions users would call (log, spy, spy-with) to macros to get this information. The output functions have also been modified to include the namespace and line number (and filename, for json output) in the default case. A slight downside to this is that the end-to-end tests include the line number in the output, so adding or removing lines from the test file causes those tests to fail... Any better ideas for how to test this much appreciated.

spy and spy-with were specifically thread-last due to the argument order. This renames them to spy->> and spy-with->> to make that explicit, and also adds a thread-first variant of each. Also updated the doc for each case to actually be correct, i.e. called in a thread-first or -last way, with data strctures that are manipulated in thread-first or -last context.

osfameron · 2017-08-15T06:36:21Z

Thanks for the PR! I've cherry-picked the testing tweak already, more comments to follow.

osfameron

Thanks, I think we can use the core of this! I do need to have a more detailed think about how to integrate it though, will have a chat over the week and hopefully find time at weekend to tweak and merge!

osfameron · 2017-08-15T06:38:00Z

test/fudge/log_test.clj

            result (with-out-str
                     (log logger :info "foo"))]
-        (is (= "2017-05-12T18:01 [fudge.log-test:128] [info] foo\n" result))))
+        (is (= "2017-05-12T18:01 [fudge.log-test:136] [info] foo\n" result))))


This kind of tweak of line numbers suggests to me that the macro stuff should be a sugar layer (possibly in fudge.sugar ;-) atop the functions, and we don't use it for the majority of the testing.

I did also consider pulling out specifically the line number parsing from the metadata to a function of it's own, then redefining that function for the tests. Problem is you can't redefine the calling-meta macro directly, and I wanted to test that it was tied in to the rest correctly

osfameron · 2017-08-15T06:40:55Z

src/fudge/log.clj


+(defmacro calling-meta
+  "Used by other macros to get the namespace, file and line of the log call.
+   Builds a def with a generated symbol to expand and evaluate for the info."


That's an implementation detail so possibly doesn't need to be in docstring. Interesting though - is there any issue with having def's everywhere there's logging? And should it be a defonce to avoid being reevaluated in loops?

defonce would probably be better for loops, yes.

As for the defs everywhere where logging, I did spend quite a while in query console and writing extra output from the test file to check the current vars in (ns-publics (all-ns)) and anywhere else I could think to check. I couldn't find these defs cluttering up the namespace anywhere. The use of (gen-sym) also means that the defs are unique and won't clash with user defs, so even if they do stay around somewhere I don't think have one additional randomly named def with no value per log call is an issue.

Done some testing with this. defonce requires a value, because it basically says "If the symbol has a value, leave it as-is. Otherwise set the symbol to arg #2". (def sym#) isn't actually setting the symbol to have a value, it's just defining the symbol as present. You can't do (defonce sym#).

osfameron · 2017-08-15T06:42:48Z

src/fudge/log.clj

       (merge {:date (call config :date-fn)
+               :ns (:ns calling-meta)
+               :file (:file calling-meta)
+               :line (:line calling-meta)


this could be (merge {:date... :level...} calling-meta) ?

I'm wondering if the calling-meta should be a) bundled in a sub-key, and/or b) passed within data.

Yes, good point r.e. the merge.

I was actually thinking that maybe data should be the sub key. That's the user provided bit, so that's the bit which might have clashing keys depending on what the user wants to output. data in a subkey stops anything like that.

osfameron · 2017-08-15T06:42:58Z

src/fudge/log.clj

-  "Log a record with the config, level, and data provided"
-  [c level data]
-  (let [record (invoke c :prepare-fn data level)]
+(defn log!


Why the exclamation mark?

Ah, if just to distinguish from the log macro, I've seen people use log-fn for the function implementation (though that's uncomfortable here, as we're using -fn for the callbacks already.) Perhaps separating macros into another namespace as I mentioned elsewhere is the thing.

It was just to distinguish the macro from the function, yes.

It shouldn't be called log! IMO as that goes against the Clojure standard. If I see ! at the end of a function, I expect it to be unsafe with respect to an STM transaction, not just impure.

As in https://github.com/bbatsov/clojure-style-guide#changing-state-fns-with-exclamation-mark ?

That only says STM-unsafe should end with !, not that nothing else should. But yeah, as above, I don't love the name anyway.

I'm open to other suggestions. I basically nicked this pattern from timbre ( https://github.com/ptaoussanis/timbre ).

osfameron · 2017-08-15T06:45:29Z

src/fudge/log.clj

+  [c level data]
+  `(log! ~c (calling-meta) ~level ~data))
+
+(defmacro spy-with->>


Good spot re ->>. I wonder if we want an alias without the punctuation noise though.

Also, why a macro?

So it can use the calling-meta macro correctly. With two macros like this, the whole lot expands into the caller's namespace, which means calling-meta gets the correct file, namespace and line. If this was a function, calling-meta would always return the file as fudge/log.clj, the namespace as fudge.log and the line as whatever line the call to calling-meta was on.

It's why I tried to leave all the complicated stuff in the log function, and have each macro do the minimum necessary to pass the function what it needs. Then there's minimal faffing with macro escaping.

Dan Meyers added 3 commits August 3, 2017 13:05

Correct test function to run within 'testing'

bfcd9ea

To match all the other tests.

osfameron reviewed Aug 15, 2017

View reviewed changes

Conversation

dancmeyers commented Aug 11, 2017

Uh oh!

osfameron commented Aug 15, 2017

Uh oh!

osfameron left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants