Module: PWN::Plugins::Log

Defined in:
lib/pwn/plugins/log.rb

Overview

This plugin is used to instantiate a PWN logger with a custom message format

Defined Under Namespace

Classes: DebugStderrTee

Constant Summary collapse

TRACE_SKIP_METHODS = 
%i[
  authors help to_s inspect class object_id hash eql? == equal? !
  method public_send send __send__ instance_eval class_eval
  public_class_method private_class_method
  debug_on? debug_progress start_debug_session quiet_debug_tui!
  loud_debug_tui! budget_scar? effective_count safe_check
  rank_for_request usable_preference? cause_crumb
].freeze
TRACE_SKIP_PREFIXES = 
%w[
  PWN::Plugins::Log
  PWN::Plugins::REPL
  PWN::Banner
].freeze
DEFAULT_TRACE_PREFIXES = 
%w[
  PWN::AI::Agent::Loop
  PWN::AI::Agent::Dispatch
].freeze
SECRET_KEY_RX = 
/password|passwd|secret|token|api[_-]?key|authorization|bearer|cookie|session[_-]?id|private[_-]?key|decryptor|credential|ssh[_-]?key|client[_-]?secret|refresh[_-]?token|access[_-]?token|id[_-]?token|vault|csrf/i
SECRET_VALUE_RX = 
%r{
  -----BEGIN\ [A-Z ]*PRIVATE\ KEY----- |
  Bearer\s+[A-Za-z0-9\-._~+/]+=* |
  \beyJ[A-Za-z0-9\-_]+\.[A-Za-z0-9\-_]+\.[A-Za-z0-9\-_]+ |
  \b(?:sk|rk|pk|xai|xox[baprs]|ghp|gho|ghu|ghs|ghr|glpat|AKIA|ASIA|ya29)[-_][A-Za-z0-9\-_]{16,} |
  \b(?:api[_-]?key|token|secret|password|passwd)\s*[:=]\s*\S+
}ix
DEBUG_VALUE_MAX = 
240
DEBUG_ARGS_MAX = 
1_800

Class Method Summary collapse

Class Method Details

.append(opts = {}) ⇒ Object

Supported Method Parameters

PWN::Log.create( )



43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
 
# File 'lib/pwn/plugins/log.rb', line 43

public_class_method def self.append(opts = {})
  level = opts[:level].to_s.downcase.to_sym
  msg = opts[:msg]
  which_self = opts[:which_self].to_s

  driver_name = File.basename($PROGRAM_NAME)

  # Only attempt to exit gracefully if level == :error
  exit_gracefully = false

  # Define Date / Time Format
  datetime_str = '%Y-%m-%d %H:%M:%S.%N%z'

  # Always append to log file
  if level == :learning
    session = SecureRandom.hex
    log_file_path = "/tmp/pwn-ai-#{session}.json" if level == :learning
    log_file = File.open(log_file_path, 'w')
  else
    log_file_path = '/tmp/pwn.log'
    log_file = File.open(log_file_path, 'a')
  end

  # Leave 10 "old" log files where
  # each file is ~ 1,024,000 bytes
  logger = Logger.new(
    log_file,
    10,
    1_024_000
  )
  logger.datetime_format = datetime_str

  case level
  when :debug
    logger.level = Logger::DEBUG
  when :error
    logger.level = Logger::ERROR
    exit_gracefully = true unless driver_name == 'pwn'
    puts "\nERROR: See #{log_file_path} for more details." if driver_name == 'pwn'
  when :fatal
    logger.level = Logger::FATAL
    puts "\n FATAL ERROR: See #{log_file_path} for more details." if driver_name == 'pwn'
  when :info, :learning
    logger.level = Logger::INFO
  when :unknown
    logger.level = Logger::UNKNOWN
  when :warn
    logger.level = Logger::WARN
  else
    level_error = "ERROR: Invalid log level. Valid options are:\n"
    level_error += ":debug\n:error\n:fatal\n:info\n:learning\n:unknown\n:warn\n"
    raise level_error
  end

  if level == :learning
    log_event = msg
    logger.formatter = proc do |_severity, _datetime, _progname, learning_arr|
      JSON.pretty_generate(
        learning_data: learning_arr
      )
    end
  else
    log_event = "driver: #{driver_name}"

    if msg.instance_of?(Interrupt)
      logger.level = Logger::WARN
      note_interrupt!(where: 'CTRL+C', which_self: which_self) if debug_enabled?
      if driver_name == 'pwn'
        log_event += ' => CTRL+C Detected.'
      else
        log_event += ' => CTRL+C Detected...Exiting Session.'
        exit_gracefully = true unless driver_name == 'pwn'
      end
    else
      log_event += " => #{msg}"
      if msg.respond_to?('backtrace') && !msg.instance_of?(Errno::ECONNRESET)
        log_event += " => \n\t#{msg.backtrace.join("\n\t")}"
        log_event += "\n\n\n"
      end
    end
  end

  logger.add(logger.level, log_event, which_self)
rescue Interrupt
  note_interrupt!(where: 'CTRL+C', which_self: self) if debug_enabled?
  puts "\n#{self}.#{__method__} => Goodbye."
rescue StandardError => e
  raise e
end

.authors ⇒ Object

Author(s)

0day Inc. support@0dayinc.com



744
745
746
747
748
 
# File 'lib/pwn/plugins/log.rb', line 744

public_class_method def self.authors
  "AUTHOR(S):
    0day Inc. <support@0dayinc.com>
  "
end

.capture_stderr!(opts = {}) ⇒ Object 



319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
 
# File 'lib/pwn/plugins/log.rb', line 319

public_class_method def self.capture_stderr!(opts = {})
  return unless debug_enabled?
  return if Thread.current[:pwn_log_stderr]

  text = opts[:text].to_s
  return if text.empty?
  return if (text: text)

  Thread.current[:pwn_log_stderr] = true
  begin
    io = @debug_file
    return if io.nil? || (io.respond_to?(:closed?) && io.closed?)

    clean = sanitize_debug_text(text: text.gsub(/\e\[[0-9;]*m/, ''))
    return if clean.strip.empty?
    return if (text: clean)

    io.write(clean.end_with?("\n") ? clean : "#{clean}\n")
    io.flush
  rescue StandardError
    nil
  ensure
    Thread.current[:pwn_log_stderr] = false
  end
  clean
end

.debug_enabled?(opts = {}) ⇒ Boolean

Returns:

  • (Boolean) 


133
134
135
136
137
 
# File 'lib/pwn/plugins/log.rb', line 133

public_class_method def self.debug_enabled?(opts = {})
  return @debug_enabled == true if opts.is_a?(Hash)

  @debug_enabled == true
end

.debug_log_path(opts = {}) ⇒ Object 



139
140
141
142
143
 
# File 'lib/pwn/plugins/log.rb', line 139

public_class_method def self.debug_log_path(opts = {})
  return @debug_path if opts.is_a?(Hash)

  @debug_path
end

.finish_request_log!(opts = {}) ⇒ Object 



201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
 
# File 'lib/pwn/plugins/log.rb', line 201

public_class_method def self.finish_request_log!(opts = {})
  return unless debug_enabled?
  return unless @debug_request_open || opts[:force] == true

  bits = [
    "footer iter=#{opts[:iter].to_i}",
    "tools_called=#{opts[:tools_called].to_i}",
    "engine_s=#{opts[:engine_s].to_f.round(3)}",
    "final_chars=#{opts[:final_chars].to_i}"
  ]
  bits << "nested=#{opts[:nested]}" unless opts[:nested].to_s.empty?
  progress(msg: bits.join(' '), which_self: self)
  @debug_request_open = false
  @debug_path
end

.help ⇒ Object

Display Usage for this Module



752
753
754
755
756
757
758
759
760
761
762
763
764
765
766
767
768
769
770
771
 
# File 'lib/pwn/plugins/log.rb', line 752

public_class_method def self.help
  puts "USAGE:
    logger = #{self}.append(
      level: 'required - log verbosity :debug|:error|:fatal|:info|:learning|:unknown|:warn',
      msg: 'required - message to log',
      which_self: 'required - pass in self object from module calling #{self}'
    )

    path = #{self}.start_debug(
      tee: $stdout,
      session_id: 'optional - pwn-ai session id'
    )
    #{self}.next_request_log!(session_id: 'optional')
    #{self}.progress(msg: 'stage', which_self: self)
    #{self}.finish_request_log!(iter: 1, tools_called: 0, engine_s: 0.2, final_chars: 12)
    #{self}.stop_debug
    # start_debug(trace: true) enables TracePoint + ENTER after each Loop step
    # (toggle-trace). Stored on Pry.config.pwn_ai_trace, not Env.
  "
end

.loud_tui!(opts = {}) ⇒ Object 



425
426
427
428
429
 
# File 'lib/pwn/plugins/log.rb', line 425

public_class_method def self.loud_tui!(opts = {})
  return if opts[:skip]

  @debug_tui_quiet = false
end

.mirror_tui!(opts = {}) ⇒ Object

Clone operator-visible TUI rows into the open RN request log (no ANSI). Used for [ ts → pwn-ai → tool ] / → result / task briefs so the file matches what the operator saw without needing a TracePoint dump.



518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
 
# File 'lib/pwn/plugins/log.rb', line 518

public_class_method def self.mirror_tui!(opts = {})
  return unless debug_enabled?
  return unless opts.is_a?(Hash)

  text = opts[:msg].to_s
  text = text.gsub(/\e\[[0-9;]*m/, '')
  text = sanitize_debug_text(text: text)
  return if text.strip.empty?

  begin
    io = @debug_file
    return if io.nil? || (io.respond_to?(:closed?) && io.closed?)

    io.write(text.end_with?("\n") ? text : "#{text}\n")
    io.flush
  rescue StandardError
    return
  end
  text
end

.next_request_log!(opts = {}) ⇒ Object 



184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
 
# File 'lib/pwn/plugins/log.rb', line 184

public_class_method def self.next_request_log!(opts = {})
  return unless debug_enabled?
  return @debug_path if @debug_request_open && opts[:force] != true

  sid = sanitize_debug_session_id(session_id: opts[:session_id])
  sid = @debug_session_id if sid.empty?
  sid = 'nosession' if sid.empty?
  @debug_session_id = sid
  n = next_debug_request_n(session_id: sid)
  path = "/tmp/pwn-ai-DEBUG-#{sid}-R#{n}.log"
  open_debug_file!(path: path)
  @debug_req_n = n
  @debug_request_open = true
  progress(msg: "request log R#{n} path=#{path}", which_self: self)
  path
end

.note_exception!(opts = {}) ⇒ Object 



498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
 
# File 'lib/pwn/plugins/log.rb', line 498

public_class_method def self.note_exception!(opts = {})
  return false unless debug_enabled?

  err = opts[:error]
  return false unless err.respond_to?(:message)

  where = opts[:where].to_s
  where = 'Loop.run' if where.empty?
  bt = Array(err.backtrace).join("\n")
  progress(
    msg: "exception #{where} #{err.class}: #{err.message}\n#{bt}",
    which_self: opts[:which_self] || self,
    keep_newlines: true,
    cap: 0
  )
end

.note_interrupt!(opts = {}) ⇒ Object 



466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
 
# File 'lib/pwn/plugins/log.rb', line 466

public_class_method def self.note_interrupt!(opts = {})
  return false unless debug_enabled?

  where = opts[:where].to_s
  where = 'CTRL+C' if where.empty?
  # CTRL+C can land mid-progress (HTTP spinner tee, tool row mirror).
  # Clear the reentrancy latch so the Interrupt stamp always lands in the
  # open RN file before the ensure footer / process unwind.
  Thread.current[:pwn_log_progress] = false
  at = Time.now
  local_ts = at.strftime('%Y-%m-%d %H:%M:%S.%L%z')
  msg = "Interrupt #{where} at=#{at.utc.iso8601(3)}"
  which = opts[:which_self] || self
  # Prefer the normal DEBUG stamp path; fall back to a direct file write
  # if progress is still unavailable for any reason.
  ok = progress(msg: msg, which_self: which)
  unless ok
    begin
      who = which.is_a?(Module) ? (which.name || which.to_s) : which.to_s
      line = "[DEBUG #{local_ts}] #{who} #{msg}".strip
      @debug_file&.puts(line)
      @debug_file&.flush
      ok = true
    rescue StandardError
      ok = false
    end
  end
  # Also clone the operator-facing TUI shape into the RN file.
  mirror_tui!(msg: "[ #{local_ts} → pwn-ai → Interrupt ] #{where}")
  ok
end

.progress(opts = {}) ⇒ Object

One progress line to the debug file and the TUI tee (same payload).



432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
 
# File 'lib/pwn/plugins/log.rb', line 432

public_class_method def self.progress(opts = {})
  return false unless debug_enabled?
  return false if Thread.current[:pwn_log_progress]

  Thread.current[:pwn_log_progress] = true
  msg = sanitize_debug_text(text: opts[:msg].to_s)
  which = opts[:which_self] || self
  line = format_progress(
    msg: msg,
    which_self: which,
    keep_newlines: opts[:keep_newlines],
    cap: opts[:cap]
  )
  begin
    @debug_file&.puts(line)
    @debug_file&.flush
  rescue StandardError
    nil
  end
  tee = opts.key?(:tee) ? opts[:tee] : @debug_tee
  if !@debug_tui_quiet && tee.respond_to?(:puts)
    begin
      tee.puts(color_progress(line: line))
      tee.flush if tee.respond_to?(:flush)
      $stdout.flush if $stdout.respond_to?(:flush)
    rescue StandardError
      nil
    end
  end
  true
ensure
  Thread.current[:pwn_log_progress] = false
end

.quiet_tui!(opts = {}) ⇒ Object 



419
420
421
422
423
 
# File 'lib/pwn/plugins/log.rb', line 419

public_class_method def self.quiet_tui!(opts = {})
  return if opts[:skip]

  @debug_tui_quiet = true
end

.raw_stderr(opts = {}) ⇒ Object 



356
357
358
359
360
 
# File 'lib/pwn/plugins/log.rb', line 356

public_class_method def self.raw_stderr(opts = {})
  return @debug_stderr_orig if opts.is_a?(Hash) && @debug_stderr_orig

  $stderr
end

.spinner_frame?(opts = {}) ⇒ Boolean

Spinner frames stay on the TTY; never persist them in the RN log.

Returns:

  • (Boolean) 


347
348
349
350
351
352
353
354
 
# File 'lib/pwn/plugins/log.rb', line 347

public_class_method def self.(opts = {})
  raw = opts[:text].to_s
  return false if raw.empty?

  stripped = raw.gsub(/\e\[[0-9;?]*[A-Za-z]/, '').delete("\r").delete("\b")
  stripped = stripped.gsub(/[\u2800-\u28FF]/, '')
  stripped.strip.empty?
end

.start_debug(opts = {}) ⇒ Object

Open a debug session. Request traces go to /tmp/pwn-ai-DEBUG-<session_id>-RN.log via next_request_log!. opts is a test override that writes to one file.



148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
 
# File 'lib/pwn/plugins/log.rb', line 148

public_class_method def self.start_debug(opts = {})
  want_trace = opts[:trace] == true
  if debug_enabled? && opts[:path].to_s.empty?
    @debug_tee = opts[:tee] if opts.key?(:tee)
    sid = sanitize_debug_session_id(session_id: opts[:session_id])
    @debug_session_id = sid unless sid.empty?
    @debug_step_io = opts[:step_io] if opts.key?(:step_io)
    apply_trace!(trace: want_trace, prefixes: opts[:prefixes]) if want_trace
    return @debug_path
  end

  stop_trace! if @debug_tp
  path = opts[:path].to_s
  @debug_tee = opts[:tee]
  @debug_tui_quiet = false
  @debug_enabled = true
  @debug_session_id = sanitize_debug_session_id(session_id: opts[:session_id])
  @debug_req_n = 0
  @debug_request_open = false
  @debug_step_io = opts[:step_io]
  if path.empty?
    close_debug_file!
    @debug_path = nil
  else
    open_debug_file!(path: path)
  end
  apply_trace!(trace: want_trace, prefixes: opts[:prefixes])
  install_stderr_tee!
  progress(msg: 'debug session start', which_self: self) if @debug_file
  @debug_path
end

.start_trace!(opts = {}) ⇒ Object 



670
671
672
673
674
675
676
677
678
679
680
681
682
683
684
685
686
687
688
689
 
# File 'lib/pwn/plugins/log.rb', line 670

public_class_method def self.start_trace!(opts = {})
  return @debug_tp if @debug_tp && opts.is_a?(Hash)

  prefixes = Array(opts[:prefixes] || DEFAULT_TRACE_PREFIXES).map(&:to_s)
  prefixes = DEFAULT_TRACE_PREFIXES if prefixes.empty?
  @debug_tp = TracePoint.new(:call) do |tp|
    next unless debug_enabled?
    next unless traceable?(tp: tp, prefixes: prefixes)

    progress(
      msg: format_trace_call(tp: tp),
      which_self: ''
    )
  rescue StandardError
    nil
  end
  @debug_tp.enable
  @debug_trace = true
  @debug_tp
end

.stop_debug(opts = {}) ⇒ Object 



217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
 
# File 'lib/pwn/plugins/log.rb', line 217

public_class_method def self.stop_debug(opts = {})
  reason = opts[:reason].to_s if opts.is_a?(Hash)
  if debug_enabled?
    tail = reason.to_s.empty? ? 'debug session stop' : "debug session stop reason=#{reason}"
    progress(msg: tail, which_self: self)
  end
  stop_trace!
  path = @debug_path
  close_debug_file!
  @debug_path = nil
  @debug_session_id = nil
  @debug_req_n = nil
  @debug_request_open = false
  @debug_tee = nil
  @debug_tui_quiet = false
  @debug_enabled = false
  @debug_step = false
  @debug_step_io = nil
  remove_stderr_tee!
  path
end

.stop_trace!(opts = {}) ⇒ Object 



691
692
693
694
695
696
697
698
 
# File 'lib/pwn/plugins/log.rb', line 691

public_class_method def self.stop_trace!(opts = {})
  return if opts[:skip]

  @debug_tp&.disable
  @debug_tp = nil
  @debug_trace = false
  @debug_step = false
end

.trace_enabled? ⇒ Boolean

Returns:

  • (Boolean) 


180
181
182
 
# File 'lib/pwn/plugins/log.rb', line 180

public_class_method def self.trace_enabled?
  @debug_trace == true
end

.wait_trace_step!(opts = {}) ⇒ Object 



700
701
702
703
704
705
706
707
708
709
710
711
712
713
714
715
716
717
 
# File 'lib/pwn/plugins/log.rb', line 700

public_class_method def self.wait_trace_step!(opts = {})
  return unless debug_enabled?
  return unless @debug_step
  return if opts[:nested]

  io = @debug_step_io || $stdin
  return unless io.respond_to?(:gets)
  return if io.equal?($stdin) && !$stdin.tty?

  label = opts[:label].to_s
  label = 'loop' if label.empty?
  progress(msg: "trace step #{label} — Press ENTER to Continue...", which_self: self, tee: nil)
  prompt_trace_enter!
  io.gets
  true
rescue StandardError
  nil
end