diary.jl file is created but nothing is written to it

[crbinz]

I'm using Diary v0.1.1 with julia v1.5.0 on mac OS. Here's my Diary.jl config file:

author = "Chris Binz"
date_format = "E U d HH:MM"
diary_name = "diary.jl"
autocommit = true
directory_mode = false
blacklist = []

When I open a new Julia session (and stay in the v1.5 environment), Diary.jl seems to be loaded correctly, and I can verify that ~/.julia/environments/v1.5/diary.jl exists. However, when I type some commands into the REPL, nothing shows up in the file.

[dalum]

That is odd! I cannot reproduce it on Linux. 😦

Can you try setting ENV["JULIA_DEBUG"] = Diary and maybe post the output? It should be quite verbose and inform you when it detects a change in the history file.

For instance, I see:

julia> ENV["JULIA_DEBUG"] = Diary
Diary

julia> a = 4
┌ Debug: Diary.jl (/tmp/jl_wyD2YF): History file has changed:
│   history_lines =
│    3-element Array{String,1}:
│     "# time: 2020-08-18 17:41:38 CEST"
│     "# mode: julia"
│     "\ta = 4"
└ @ Diary ~/.julia/packages/Diary/wSV6U/src/Diary.jl:69
┌ Debug: Diary.jl: mode line found: julia
└ @ Diary ~/.julia/packages/Diary/wSV6U/src/Diary.jl:124
┌ Debug: Diary.jl: using /home/dalum/.julia/environments/v1.5 as diary root folder
└ @ Diary ~/.julia/packages/Diary/wSV6U/src/Diary.jl:210
┌ Debug: Diary.jl: committing 1 lines to /home/dalum/.julia/environments/v1.5/diary.jl
└ @ Diary ~/.julia/packages/Diary/wSV6U/src/Diary.jl:290
4

[dalum]

Also, just to be sure, could you check that your configuration matches with the output of Diary.read_configuration(), to make sure that it has been parsed correctly?

[crbinz]

Hmm, all I see is

julia> ENV["JULIA_DEBUG"] = Diary
Diary

julia> a =4
4

julia> 

and

julia> Diary.read_configuration()
Dict{String,Any} with 7 entries:
  "author"             => "Chris Binz"
  "blacklist"          => Any[]
  "persistent_history" => true
  "autocommit"         => true
  "date_format"        => "E U d HH:MM"
  "diary_name"         => "diary.jl"
  "directory_mode"     => false

[dalum]

Okay, could you try running the tests? ] test Diary. I don't have a Mac, but they pass Travis CI for Mac OS, so would be nice to know if they are somehow not catching this behaviour.

Also, can you try starting Julia with JULIA_DEBUG=Diary julia? That should show you some more info about which file Diary.jl is tracking. You should see something like:

> JULIA_DEBUG=Diary julia
               _
   _       _ _(_)_     |  Documentation: https://docs.julialang.org
  (_)     | (_) (_)    |
   _ _   _| |_  __ _   |  Type "?" for help, "]?" for Pkg help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 1.5.0 (2020-08-01)
 _/ |\__'_|_|_|\__'_|  |  Official https://julialang.org/ release
|__/                   |

┌ Debug: Diary.jl: Watching: /tmp/jl_DwjoLj
└ @ Diary ~/.julia/packages/Diary/wSV6U/src/Diary.jl:36
julia>

Then you can manually inspect the file that it is watching, and see if it is actually changing. Perhaps there are some write permissions that prevent Julia from writing to the history file, or perhaps FileWatching isn't working properly.

[crbinz]

Tests seem to fail:

(@v1.5) pkg> test Diary
    Testing Diary
Status `/private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/Project.toml`
  [601e5a01] Diary v0.1.1
  [7b1f6079] FileWatching
  [44cfe95a] Pkg
  [8dfed614] Test
Status `/private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/Manifest.toml`
  [601e5a01] Diary v0.1.1
  [2a0f44e3] Base64
  [ade2ca70] Dates
  [8ba89e20] Distributed
  [7b1f6079] FileWatching
  [b77e0a4c] InteractiveUtils
  [76f85450] LibGit2
  [8f399da3] Libdl
  [56ddb016] Logging
  [d6f4376e] Markdown
  [44cfe95a] Pkg
  [de0858da] Printf
  [3fa0cd96] REPL
  [9a3f8284] Random
  [ea8e919c] SHA
  [9e88b42a] Serialization
  [6462fe0b] Sockets
  [8dfed614] Test
  [cf7118a7] UUIDs
  [4ec0a83e] Unicode
┌ Debug: Diary.jl: mode line found: julia
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:124
┌ Debug: Diary.jl: mode line found: julia
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:124
┌ Debug: Diary.jl: mode line found: pkg
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:124
┌ Debug: Diary.jl: got command: commit
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:132
┌ Debug: Diary.jl: using /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7 as diary root folder
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:177
┌ Debug: Diary.jl: committing 0 lines to /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/diary.jl
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:269
Test Summary:   | Pass  Total
History Parsing |    4      4
┌ Debug: Diary.jl: using /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7 as diary root folder
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:177
┌ Debug: Diary.jl: committing 0 lines to /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/diary.jl
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:269
┌ Debug: Diary.jl: using /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7 as diary root folder
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:177
┌ Debug: Diary.jl: committing 0 lines to /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/diary.jl
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:269
Test Summary:   | Pass  Total
Command Parsing |    4      4
 Activating environment at `/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/Project.toml`
Test Summary:         | Pass  Total
Finding configuration |    4      4
 Activating environment at `/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/Project.toml`
┌ Debug: Diary.jl: using /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7 as diary root folder
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:177
┌ Debug: Diary.jl: JULIA_DIARY = /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/env_diary.jl
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:188
 Activating environment at `~/.julia/environments/v1.5/Project.toml`
┌ Debug: Diary.jl: using /Users/cbinz/.julia/environments/v1.5 as diary root folder
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:177
Finding Diary: Test Failed at /Users/cbinz/.julia/packages/Diary/uKyr1/test/runtests.jl:102
  Expression: isnothing(Diary.find_diary())
Stacktrace:
 [1] top-level scope at /Users/cbinz/.julia/packages/Diary/uKyr1/test/runtests.jl:102
 [2] top-level scope at /Users/julia/buildbot/worker/package_macos64/build/usr/share/julia/stdlib/v1.5/Test/src/Test.jl:1115
 [3] top-level scope at /Users/cbinz/.julia/packages/Diary/uKyr1/test/runtests.jl:86
 Activating environment at `/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/Project.toml`
┌ Debug: Diary.jl: using /private/var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_hJmTp7/jl_AWGaed as diary root folder
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:177
Test Summary: | Pass  Fail  Total
Finding Diary |    5     1      6
ERROR: LoadError: Some tests did not pass: 5 passed, 1 failed, 0 errored, 0 broken.
in expression starting at /Users/cbinz/.julia/packages/Diary/uKyr1/test/runtests.jl:85
ERROR: Package Diary errored during testing

(@v1.5) pkg> 

and

~ > JULIA_DEBUG=Diary julia                                                                             

               _
   _       _ _(_)_     |  Documentation: https://docs.julialang.org
  (_)     | (_) (_)    |
   _ _   _| |_  __ _   |  Type "?" for help, "]?" for Pkg help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 1.5.0 (2020-08-01)
 _/ |\__'_|_|_|\__'_|  |  Official https://julialang.org/ release
|__/                   |

┌ Debug: Diary.jl: Watching: /var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_RV0wQv
└ @ Diary ~/.julia/packages/Diary/uKyr1/src/Diary.jl:36
julia> 

[dalum]

Thanks! Good to know that the tests at least reflect that it doesn't work properly on your system. 😅

If you could try to write something in the terminal after you've started it in debug mode, and see if you can see that reflected at the bottom of the file that is being watched, then we can figure out if the culprit is Julia not writing to it, or if it is because it isn't detecting the changes. Also note that the REPL has a slight quirk, so if you press up and run the most recent thing you typed, it isn't saved to the history file, even if you started a new session, so just type something new or press up twice.

[crbinz]

The watched file appears to contain an awful lot of REPL history going back months, but the commands I type are indeed saved to the end of it:

~ > tail /var/folders/sm/j5dkyxzs38l0gp30b8wv78340000gn/T/jl_mHqPrP                                        
        using Diary
# time: 2020-08-17 15:37:25 EDT
# mode: julia
        exit()
# time: 2020-08-18 16:06:04 EDT
# mode: julia
        a = 1
# time: 2020-08-18 16:06:07 EDT
# mode: julia
        a*3

[dalum]

Okay, so it must be related to FileWatching, good to know. I will add an option to use file polling instead, which should hopefully fix it for you. I think Revise does something similar.

The error you got from the test is actually not related to this issue, it is an error with the test. That test should test that v1.5 environment is blacklisted by default, but instead it used your configuration, so it failed because it wasn't blacklisted with your configuration. I will fix both of these in v0.1.3, which will be released shortly, which also adds backwards compatibility with v1.4.

[dalum]

@crbinz A new version (v0.1.3) has been registered, which has a new option file_polling. I suggest you try first without it, and see if some of the other changes have somehow made it work, but if not, then give file_polling = true a try. You might have to adjust file_polling_interval to make it work properly, but a value of 1.0 (seconds) seems to work fine for me and Travis CI.

[crbinz]

v0.1.3 works, but only when I add file_polling = true to Diary.toml.

[dalum]

Great! I will mark this as closed then.

[crbinz]

Thanks for your help!