fix: logging of steps in verbose and debug mode (#5312)

* Initial plan

* Fix: Emit step events for MetaSteps without child steps

* docs: Add documentation for step logging fix

---------

Co-authored-by: copilot-swe-agent[bot] <198982749+Copilot@users.noreply.github.com>

Author: Copilot

STEP_LOGGING_FIX.md

@@ -0,0 +1,45 @@
+# Step Logging Fix Documentation
+
+## Problem Statement
+Steps were not printed in logs when running either `--verbose` or `--debug` when the I actor method is called not directly in Scenario test file (e.g., in custom steps or page objects) and the custom step doesn't call any child I steps.
+
+## Root Cause
+The `MetaStep.run()` method in `lib/step/meta.js` never emitted `event.step.started` and `event.step.finished` events for itself. It only registered a listener to attach itself to child steps. If no child steps were called, the MetaStep was never printed in verbose/debug output.
+
+## Solution
+Modified `lib/step/meta.js` to track whether child steps are registered and conditionally emit events only if no children are registered. This prevents duplicate printing while ensuring standalone MetaSteps are visible in output.
+
+## Files Changed
+1. `lib/step/meta.js` - Core logic fix
+2. `test/unit/step/meta_step_logging_test.js` - Comprehensive unit tests
+
+## Testing
+- ✅ 6 new unit tests (all passing)
+- ✅ Manual testing with custom steps (verified fix works)
+- ✅ Existing tests (no regression)
+- ✅ Security scan (CodeQL: 0 alerts)
+- ✅ Linting (ESLint: 0 errors)
+
+## Example Output
+
+### Before Fix
+```
+  test with custom step WITHOUT I calls
+  Scenario()
+This is just a console.log
+  ✔ OK in 5ms
+```
+❌ Step name "I customStepWithoutI" is NOT printed
+
+### After Fix
+```
+  test with custom step WITHOUT I calls
+  Scenario()
+This is just a console.log
+    I custom step without i 
+  ✔ OK in 6ms
+```
+✅ Step name is now visible!
+
+## Known Limitation
+For synchronous MetaSteps without child steps, the step name appears after the function executes (because events are emitted in the finally block). This is an acceptable trade-off to avoid the complexity of predicting whether child steps will be registered.

lib/step/meta.js

@@ -58,17 +58,24 @@ class MetaStep extends Step {
     this.status = 'queued'
     this.setArguments(Array.from(arguments).slice(1))
     let result
+    let hasChildSteps = false
 
     const registerStep = step => {
       this.setMetaStep(null)
       step.setMetaStep(this)
+      hasChildSteps = true
     }
     event.dispatcher.prependListener(event.step.before, registerStep)
+
+    // Start timing
+    this.startTime = Date.now()
+
     // Handle async and sync methods.
     if (fn.constructor.name === 'AsyncFunction') {
       result = fn
         .apply(this.context, this.args)
         .then(result => {
+          this.setStatus('success')
           return result
         })
         .catch(error => {
@@ -78,17 +85,27 @@ class MetaStep extends Step {
         .finally(() => {
           this.endTime = Date.now()
           event.dispatcher.removeListener(event.step.before, registerStep)
+          // Only emit events if no child steps were registered
+          if (!hasChildSteps) {
+            event.emit(event.step.started, this)
+            event.emit(event.step.finished, this)
+          }
         })
     } else {
       try {
-        this.startTime = Date.now()
         result = fn.apply(this.context, this.args)
+        this.setStatus('success')
       } catch (error) {
         this.setStatus('failed')
         throw error
       } finally {
         this.endTime = Date.now()
         event.dispatcher.removeListener(event.step.before, registerStep)
+        // Only emit events if no child steps were registered
+        if (!hasChildSteps) {
+          event.emit(event.step.started, this)
+          event.emit(event.step.finished, this)
+        }
       }
     }
 

test/unit/step/meta_step_logging_test.js

@@ -0,0 +1,115 @@
+import { expect } from 'chai'
+import sinon from 'sinon'
+import event from '../../../lib/event.js'
+import MetaStep from '../../../lib/step/meta.js'
+import Step from '../../../lib/step.js'
+
+describe('MetaStep Logging', () => {
+  let eventStub
+
+  beforeEach(() => {
+    event.cleanDispatcher()
+    eventStub = {
+      stepStarted: sinon.spy(),
+      stepFinished: sinon.spy(),
+    }
+    event.dispatcher.on(event.step.started, eventStub.stepStarted)
+    event.dispatcher.on(event.step.finished, eventStub.stepFinished)
+  })
+
+  afterEach(() => {
+    event.cleanDispatcher()
+  })
+
+  it('should emit step.started and step.finished for MetaStep without child steps', () => {
+    const metaStep = new MetaStep('I', 'doSomething')
+    const fn = () => {
+      // MetaStep that doesn't call any child I steps
+      console.log('Just a console.log')
+    }
+
+    metaStep.run(fn)
+
+    // Should emit step.started and step.finished
+    expect(eventStub.stepStarted.calledOnce).to.be.true
+    expect(eventStub.stepFinished.calledOnce).to.be.true
+    expect(eventStub.stepStarted.firstCall.args[0]).to.equal(metaStep)
+    expect(eventStub.stepFinished.firstCall.args[0]).to.equal(metaStep)
+  })
+
+  it('should NOT emit events for MetaStep WITH child steps', () => {
+    const metaStep = new MetaStep('I', 'doSomethingWithChild')
+    const fn = () => {
+      // Simulate a child step being registered
+      const childStep = new Step({ helper: 'test' }, 'childAction')
+      event.emit(event.step.before, childStep)
+    }
+
+    metaStep.run(fn)
+
+    // Should NOT emit step.started and step.finished for the MetaStep
+    // because it has child steps
+    expect(eventStub.stepStarted.called).to.be.false
+    expect(eventStub.stepFinished.called).to.be.false
+  })
+
+  it('should emit events for async MetaStep without child steps', async () => {
+    const metaStep = new MetaStep('I', 'doSomethingAsync')
+    const fn = async () => {
+      // Async MetaStep that doesn't call any child I steps
+      await Promise.resolve()
+      console.log('Just an async operation')
+    }
+
+    await metaStep.run(fn)
+
+    // Should emit step.started and step.finished
+    expect(eventStub.stepStarted.calledOnce).to.be.true
+    expect(eventStub.stepFinished.calledOnce).to.be.true
+    expect(eventStub.stepStarted.firstCall.args[0]).to.equal(metaStep)
+    expect(eventStub.stepFinished.firstCall.args[0]).to.equal(metaStep)
+  })
+
+  it('should NOT emit events for async MetaStep WITH child steps', async () => {
+    const metaStep = new MetaStep('I', 'doSomethingAsyncWithChild')
+    const fn = async () => {
+      // Simulate a child step being registered
+      const childStep = new Step({ helper: 'test' }, 'childAction')
+      event.emit(event.step.before, childStep)
+      await Promise.resolve()
+    }
+
+    await metaStep.run(fn)
+
+    // Should NOT emit step.started and step.finished for the MetaStep
+    // because it has child steps
+    expect(eventStub.stepStarted.called).to.be.false
+    expect(eventStub.stepFinished.called).to.be.false
+  })
+
+  it('should set status to success when MetaStep completes without error', () => {
+    const metaStep = new MetaStep('I', 'doSomething')
+    const fn = () => {
+      return 'success'
+    }
+
+    metaStep.run(fn)
+
+    expect(metaStep.status).to.equal('success')
+  })
+
+  it('should set status to failed when MetaStep throws error', () => {
+    const metaStep = new MetaStep('I', 'doSomethingThatFails')
+    const fn = () => {
+      throw new Error('Test error')
+    }
+
+    try {
+      metaStep.run(fn)
+    } catch (err) {
+      // Expected to throw
+    }
+
+    expect(metaStep.status).to.equal('failed')
+  })
+})