log: add leveled log

app/cmd/nes.go

@@ -11,9 +11,9 @@ import (
 	"time"
 
 	"github.com/icexin/eggos/app"
-	"github.com/icexin/eggos/debug"
 	"github.com/icexin/eggos/drivers/kbd"
 	"github.com/icexin/eggos/drivers/vbe"
+	"github.com/icexin/eggos/log"
 
 	"github.com/fogleman/nes/nes"
 	"golang.org/x/image/draw"
@@ -117,7 +117,7 @@ func runGame(rom io.Reader, scaler draw.Interpolator) error {
 		sum += used
 		cnt++
 		if cnt%30 == 0 {
-			debug.Logf("used %s", sum/time.Duration(cnt))
+			log.Infof("used %s", sum/time.Duration(cnt))
 			cnt = 0
 			sum = 0
 		}

drivers/e1000/e1000.go

@@ -6,12 +6,12 @@ import (
 	"time"
 	"unsafe"
 
-	"github.com/icexin/eggos/debug"
 	"github.com/icexin/eggos/drivers/pci"
 	"github.com/icexin/eggos/drivers/pic"
 	"github.com/icexin/eggos/inet"
 	"github.com/icexin/eggos/kernel/mm"
 	"github.com/icexin/eggos/kernel/sys"
+	"github.com/icexin/eggos/log"
 
 	"gvisor.dev/gvisor/pkg/tcpip/buffer"
 	"gvisor.dev/gvisor/pkg/tcpip/stack"
@@ -131,7 +131,7 @@ func (d *driver) Init(dev *pci.Device) error {
 
 	d.dev = dev
 
-	debug.Logf("[e1000] enable bus master")
+	log.Infof("[e1000] enable bus master")
 	dev.Addr.EnableBusMaster()
 
 	// mmap bar address
@@ -141,7 +141,7 @@ func (d *driver) Init(dev *pci.Device) error {
 	}
 	mm.SysFixedMmap(uintptr(baddr), uintptr(baddr), uintptr(blen))
 	d.bar = uintptr(baddr)
-	debug.Logf("[e1000] mmap for bar0 0x%x", d.bar)
+	log.Infof("[e1000] mmap for bar0 0x%x", d.bar)
 
 	// alloc desc
 	descptr := mm.Alloc()
@@ -152,21 +152,21 @@ func (d *driver) Init(dev *pci.Device) error {
 	// disable all intrs
 	d.writecmd(REG_IMC, 0xffffffff)
 
-	debug.Logf("[e1000] begin reset")
+	log.Infof("[e1000] begin reset")
 	// Reset the device.
 	d.writecmd(REG_CTRL, d.readcmd(REG_CTRL)|CTRL_RST)
 
 	// Wait until the device gets reset.
 	// for (d.readcmd(REG_CTRL) & CTRL_RST) != 0 {
 	// }
 	time.Sleep(time.Microsecond)
-	debug.Logf("[e1000] reset done")
+	log.Infof("[e1000] reset done")
 	// again disable all intrs after reset
 	d.writecmd(REG_IMC, 0xffffffff)
 
 	// Link up!
 	d.writecmd(REG_CTRL, d.readcmd(REG_CTRL)|CTRL_SLU|CTRL_ASDE)
-	debug.Logf("[e1000] link up")
+	log.Infof("[e1000] link up")
 
 	// Fill Multicast Table Array with zeros.
 	for i := uint16(0); i < 0x80; i++ {
@@ -213,9 +213,9 @@ func (d *driver) Init(dev *pci.Device) error {
 	d.readcmd(REG_ICR)
 	d.writecmd(REG_ICR, ^uint32(0))
 
-	debug.Logf("[e1000] begin read mac")
+	log.Infof("[e1000] begin read mac")
 	d.readmac()
-	debug.Logf("[e1000] mac:%x", d.mac)
+	log.Infof("[e1000] mac:%x", d.mac)
 	// go d.recvloop()
 	return nil
 }
@@ -244,15 +244,15 @@ func (d *driver) Transmit(pkt *stack.PacketBuffer) error {
 
 	// for atomic.LoadInt32((*int32)(unsafe.Pointer(&desc.status))) == 0 {
 	// }
-	// debug.Logf("[e1000] send %d bytes", pktlen)
+	// log.Infof("[e1000] send %d bytes", pktlen)
 	return nil
 }
 
 func (d *driver) Intr() {
 	defer pic.EnableIRQ(uint16(d.dev.IRQLine))
 	defer pic.EOI(uintptr(d.dev.IRQNO))
 	cause := d.readcmd(REG_ICR)
-	// debug.Logf("[e1000] cause %x", cause)
+	// log.Infof("[e1000] cause %x", cause)
 	// clear ICR register
 	// e1000e may not clear upon read
 	d.writecmd(REG_ICR, ^uint32(0))
@@ -278,9 +278,9 @@ func (d *driver) recvloop() {
 func (d *driver) readpkt() bool {
 	d.rxidx = d.readcmd(REG_RDT)
 	d.rxidx = (d.rxidx + 1) % NUM_RX_DESCS
-	// debug.Logf("[e1000] head:%d", d.readcmd(0x02810))
-	// debug.Logf("[e1000] tail:%d", d.readcmd(0x02818))
-	// debug.Logf("[e1000] rxidx:%d", d.rxidx)
+	// log.Infof("[e1000] head:%d", d.readcmd(0x02810))
+	// log.Infof("[e1000] tail:%d", d.readcmd(0x02818))
+	// log.Infof("[e1000] rxidx:%d", d.rxidx)
 	desc := &d.rxdescs[d.rxidx]
 
 	// fmt.Printf("status:%x\n", atomic.LoadUint32((*uint32)(unsafe.Pointer(&desc.status))))
@@ -291,7 +291,7 @@ func (d *driver) readpkt() bool {
 	}
 
 	buf := sys.UnsafeBuffer(uintptr(desc.paddr), int(desc.len))
-	// debug.Logf("[e1000] read %d bytes", desc.len)
+	// log.Infof("[e1000] read %d bytes", desc.len)
 	if d.rxfunc != nil {
 		d.rxfunc(buf)
 	}

drivers/pci/pci.go

@@ -1,9 +1,9 @@
 package pci
 
 import (
-	"github.com/icexin/eggos/debug"
 	"github.com/icexin/eggos/drivers/pic"
 	"github.com/icexin/eggos/kernel/trap"
+	"github.com/icexin/eggos/log"
 )
 
 type Identity struct {
@@ -74,10 +74,10 @@ func Init() {
 	for _, driver := range drivers {
 		dev := findDev(driver.Idents())
 		if dev == nil {
-			debug.Logf("[pci] no pci device found for %v\n", driver.Name())
+			log.Infof("[pci] no pci device found for %v\n", driver.Name())
 			continue
 		}
-		debug.Logf("[pci] found %x:%x for %s, irq:%d\n", dev.Ident.Vendor, dev.Ident.Device, driver.Name(), dev.IRQNO)
+		log.Infof("[pci] found %x:%x for %s, irq:%d\n", dev.Ident.Vendor, dev.Ident.Device, driver.Name(), dev.IRQNO)
 		driver.Init(dev)
 		pic.EnableIRQ(uint16(dev.IRQLine))
 		trap.Register(int(dev.IRQNO), driver.Intr)

drivers/ps2/mouse/mouse.go

@@ -41,12 +41,12 @@ func intr() {
 	pic.EOI(_IRQ_MOUSE)
 	for {
 		st := ps2.ReadCmd()
-		// debug.Logf("status:%08b", st)
+		// log.Infof("status:%08b", st)
 		if st&0x01 == 0 {
 			break
 		}
 		x := ps2.ReadDataNoWait()
-		// debug.Logf("data:%08b", x)
+		// log.Infof("data:%08b", x)
 		handlePacket(x)
 	}
 }
@@ -84,7 +84,7 @@ func handlePacket(v byte) {
 		default:
 		}
 	}
-	// debug.Logf("x:%d y:%d packet:%v status:%8b", xpos, ypos, packet, status)
+	// log.Infof("x:%d y:%d packet:%v status:%8b", xpos, ypos, packet, status)
 }
 
 func xrel(status byte, value int) int {

inet/dhcp/client.go

@@ -9,13 +9,12 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"log"
 	"math/rand"
 	"net"
 	"sync"
 	"time"
 
-	"github.com/icexin/eggos/debug"
+	"github.com/icexin/eggos/log"
 
 	"gvisor.dev/gvisor/pkg/tcpip"
 	"gvisor.dev/gvisor/pkg/tcpip/adapters/gonet"
@@ -55,15 +54,13 @@ func NewClient(s *stack.Stack, nicid tcpip.NICID, linkAddr tcpip.LinkAddress) *C
 func (c *Client) Start() {
 	go func() {
 		for {
-			log.Print("DHCP request")
 			ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second)
 			err := c.Request(ctx, "")
 			cancel()
 			if err == nil {
 				break
 			}
 		}
-		log.Printf("DHCP acquired IP %s for %s", c.Address(), c.Config().LeaseLength)
 	}()
 }
 
@@ -171,7 +168,7 @@ func (c *Client) Request(ctx context.Context, requestedAddr tcpip.Address) error
 	if err != nil {
 		return fmt.Errorf("dhcp offer: %v", err)
 	}
-	debug.Logf("[dhcp] offer done")
+	log.Infof("[dhcp] offer done")
 
 	var ack bool
 	var cfg Config
@@ -207,7 +204,7 @@ func (c *Client) Request(ctx context.Context, requestedAddr tcpip.Address) error
 		{optReqIPAddr, []byte(addr)},
 		{optDHCPServer, []byte(cfg.ServerAddress)},
 	})
-	debug.Logf("[dhcp] offer ip:%s server:%s", addr, cfg.ServerAddress)
+	log.Infof("[dhcp] offer ip:%s server:%s", addr, cfg.ServerAddress)
 	_, err = conn.WriteTo(h, serverAddr)
 	if err != nil {
 		return err
@@ -239,7 +236,7 @@ func (c *Client) Request(ctx context.Context, requestedAddr tcpip.Address) error
 	if !ack {
 		return fmt.Errorf("dhcp: request not acknowledged")
 	}
-	debug.Logf("[dhcp] lease:%s", cfg.LeaseLength)
+	log.Infof("[dhcp] lease:%s", cfg.LeaseLength)
 	if cfg.LeaseLength != 0 {
 		go c.renewAfter(cfg.LeaseLength)
 	}
@@ -261,7 +258,7 @@ func (c *Client) renewAfter(d time.Duration) {
 		case <-ctx.Done():
 		case <-timer.C:
 			if err := c.Request(ctx, c.addr); err != nil {
-				log.Printf("address renewal failed: %v", err)
+				log.Errorf("address renewal failed: %v", err)
 				go c.renewAfter(1 * time.Minute)
 			}
 		}