<jupyter_start><jupyter_text>Extracting information from log files - Introducing "grblogtools"When running Gurobi, you will almost always create a log file. However, this name does not do it justice since the log file contains a lot of run time information about Gurobi which is critical to understand its behaviour and how to fine tune it. Consider the following excerpt from a log file:```   Nodes    |    Current Node    |     Objective Bounds      |     WorkExpl Unexpl |  Obj  Depth IntInf | Incumbent    BestBd   Gap | It/Node Time[...]   460   223 infeasible   15        93.00963   84.27981  9.39%   901  110s   524   241   87.92940    7  871   93.00963   84.58489  9.06%   861  116s   596   258     cutoff   11        93.00963   84.85854  8.76%   826  121s   656   272   89.29969    8 1040   93.00963   84.90537  8.71%   815  126s   686   282   92.56059   14  937   93.00963   84.90537  8.71%   811  150sH  688   232                      91.0097041   84.90537  6.71%   810  150s   698   236     cutoff   17        91.00970   84.92462  6.69%   812  155sH  712   236                      91.0096929   84.92462  6.69%   806  155s   754   248   86.43035    7  869   91.00969   84.93340  6.68%   806  162s   781   248   89.49467    9 1173   91.00969   85.17626  6.41%   799  165s   847   274   87.93092   11  958   91.00969   85.24404  6.34%   804  172sH  878   274                      91.0096855   85.24404  6.34%   795  172s   885   286     cutoff   15        91.00969   85.45226  6.11%   802  176s   926   290   90.42360   14  553   91.00969   85.52184  6.03%   805  181s[...]```A lot of things are happening here! You can see the progress of the branch-and-bound tree (first 2 columns), when a heuristic has been found (the little `H` on the left), information about the best solution and best bound (columns 6-8), and much more!So what can you do with this information? Up until now, you needed to "read" the log files, i.e., open them up and figure out what is going on by going through it line by line. *But this is about to change!*  What is "grblogtools"In short, `grblogtools` is an [open-source Python package](https://github.com/Gurobi/grblogtools) written by our Support team that reads the log file(s) for you and makes them available as a pandas dataframe or an Excel spreadsheet. When using Python, there are also a few nifty routines that allow you to create nice plots from your log files in a few lines of code. All you need to do is run `pip install grblogtools` and you're good to go!  Single log file analysisLet's start with the simplest case, reading and analysing a single log file:<jupyter_code>import grblogtools as glt
summary = glt.get_dataframe(["data/912-glass4-0.log"])<jupyter_output><empty_output><jupyter_text>And we're done! Now all the information in the log file is converted into a standard dataframe. Let's have a look!<jupyter_code>summary<jupyter_output><empty_output><jupyter_text>Multiple log file analysisWhile it's nice to parse a single log file into a dataframe, `grblogtools` really comes into its own when you start reading in multiple log files. Then, each log file simply becomes a separate row in the dataframe:<jupyter_code>summary = glt.get_dataframe(["data/912*.log"])<jupyter_output><empty_output><jupyter_text>This just read in 63 different log files and parsed their contents into a pandas dataframe:<jupyter_code>summary<jupyter_output><empty_output><jupyter_text>VisualizationsNow that we have all this data at our (pythonic) fingertips, we can start doing all sorts of analysis. For the ones that we come across the most at Gurobi, we actually implemented a few `ipywidgets` which we will now show below. `glt.plot()` is an interactive wrapper around the plotting functions from `plotly.express`. This means that to get started, you only need to run `glt.plot(summary)` to get a widget where you can play around with your data!<jupyter_code>glt.plot(summary)<jupyter_output><empty_output><jupyter_text>All available columns in the DataFrame can be selected for plotting. All interactive parameters can also be set upfront to get the desired figure right away:<jupyter_code>glt.plot(summary.sort_values(by="Runtime"), 
         type="box", 
         color="Log", 
         log_y=True, 
         title="Gurobi Performance")<jupyter_output><empty_output><jupyter_text>One more thing... timelines!So far, we only worked with the "final" results of the log file, e.g. runtime, MIP gap, etc. But `grblogtools` actually can parse entire log files! All you need to do is to set the additional parameter `timelines=True` when parsing our log files:<jupyter_code>summary, timelines = glt.get_dataframe(["data/912*.log"], timelines=True)<jupyter_output><empty_output><jupyter_text>This simply creates two more dataframes, `timelines["nodelog"]` and `timelines["rootlp"]`, which contain the information about the LP relaxation and node log. Let's have a look at them:<jupyter_code>timelines["nodelog"]
timelines["rootlp"]<jupyter_output><empty_output><jupyter_text>Note that the `timelines["rootlp"]` DataFrame does not contain any information because the root solving process was so quick that there are no lines printed in the respective part of the log files:[...]Presolve removed 6 rows and 6 columnsPresolve time: 0.00sPresolved: 390 rows, 316 columns, 1803 nonzerosVariable types: 19 continuous, 297 integer (297 binary)Found heuristic solution: objective 3.133356e+09Root relaxation: objective 8.000024e+08, 72 iterations, 0.00 seconds    Nodes    |    Current Node    |     Objective Bounds      |     Work Expl Unexpl |  Obj  Depth IntInf | Incumbent    BestBd   Gap | It/Node Time     0     0 8.0000e+08    0   72 3.1334e+09 8.0000e+08  74.5%     -    0sH    0     0                    2.200019e+09 8.0000e+08  63.6%     -    0s[...]This additional information allows for visualizations of the **solving progress**, for example the primal/dual bound improvement:<jupyter_code>nl = timelines["nodelog"]
glt.plot(nl[nl["Log"] == "912-Cuts0-Heuristics0.1"], title="912-Cuts0-Heuristics0.1", type="line", y="Gap", color="Seed", log_x=True)<jupyter_output><empty_output><jupyter_text>**Why is there such a big difference between the same parameter settings and the different seeds?**When you see something like this, it's a good idea to check the log files again for more clues on how this behavior occured.  The sky is the limit - customizing your plotsSince `grblogtools` simply returns pandas dataframes, you can use all the standard Python machinery to draw more customizable plots. We like `plotly`, so here are a couple of examples of using the fully featured `plotly` library. First, let's have a look at an example of plotting the primal and dual bound progress using filled charts:<jupyter_code>import plotly.graph_objects as go

default_run = nl[(nl["Log"] == "912") & (nl["Seed"] == "0")]

fig = go.Figure()
fig.add_trace(go.Scatter(x=default_run["Time"], y=default_run["Incumbent"], name="Primal Bound"))
fig.add_trace(go.Scatter(x=default_run["Time"], y=default_run["BestBd"], fill="tonexty", name="Dual Bound"))
fig.update_xaxes(title_text="Runtime")
fig.update_yaxes(title_text="Objective function value")
fig.show()<jupyter_output><empty_output><jupyter_text>Remember that run with the very different run times using `Cuts=0` and `Heuristics=0.1`? Let's have a closer look at that:<jupyter_code>from plotly.subplots import make_subplots

selected_run = nl[nl["Log"] == "912-Cuts0-Heuristics0.1"] 
fastest_run = selected_run[selected_run["Seed"] == "1"]
slowest_run = selected_run[selected_run["Seed"] == "2"]

fig = make_subplots(rows=2, cols=1)
fig.append_trace(go.Scatter(x=slowest_run["Time"], y=slowest_run["Incumbent"], 
                            name="Primal Bound - Seed 1"), row=1, col=1)
fig.append_trace(go.Scatter(x=slowest_run["Time"], y=slowest_run["BestBd"], 
                            fill="tonexty", name="Dual Bound - Seed 1"), row=1, col=1)

fig.append_trace(go.Scatter(x=fastest_run["Time"], y=fastest_run["Incumbent"], 
                            name="Primal Bound - Seed 2"), row=2, col=1)
fig.append_trace(go.Scatter(x=fastest_run["Time"], y=fastest_run["BestBd"], 
                            fill="tonexty", name="Dual Bound - Seed 2"), row=2, col=1)

fig.update_layout(title_text="Comparing bound progression between 2 random seeds")
fig.update_xaxes(title_text="Runtime")
fig.update_yaxes(title_text="Objective function value")
fig.show()<jupyter_output><empty_output><jupyter_text>We can also plot the gap, that is, the difference between primal and dual bound, to combine both bound improvements into one line:<jupyter_code>nl2 = nl[nl["Log"].isin(["912-Cuts0-Heuristics0.1", "912"])]
glt.plot(nl2, type="line", log_x=True, y="Gap", symbol="Seed")<jupyter_output><empty_output><jupyter_text>One more thing... Excel output!If you prefer working in Excel rather than in Python to explore your data, you can also directly create Excel worksheets from your log files using `grblogtools` as a command-line tool:<jupyter_code>! python -m grblogtools analysis.xlsx data/*.log<jupyter_output><empty_output>
{'fraction_non_alphanumeric': 0.09487207642472822, 'fraction_numerical': 0.07345997584275832, 'mean_word_length': 3.9879518072289155, 'pattern_counts': {'":': 0, '<': 53, '<?xml version=': 0, '>': 53, 'https://': 1, 'lorem ipsum': 0, 'www.': 0, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 0, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'chain_length': '13', 'dir': 'jupyter-structured-clean-dedup', 'id': '163468', 'license': 'Apache-2.0', 'n_tokens_mistral': 3319, 'n_tokens_neox': 2847, 'n_words': 1027, 'path': 'grblogtools.ipynb', 'repo_name': 'ronaldvdv/grblogtools', 'size': '9107'}