Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
35 changes: 35 additions & 0 deletions cni/log/logger.go
Original file line number Diff line number Diff line change
@@ -1,8 +1,11 @@
package log

import (
"fmt"
"os"
"path/filepath"

"github.com/sirupsen/logrus"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"gopkg.in/natefinch/lumberjack.v2"
Expand Down Expand Up @@ -38,11 +41,43 @@ func initZapLog(logFile string) *zap.Logger {
// If we fail to join the platform cores, fallback to the original core.
core = textFileCore
}

return zap.New(core, zap.AddCaller()).With(zap.Int("pid", os.Getpid()))
}

// InitHcnshimFileLogger creates (if missing) and sets a dedicated log file
// for all hcnshim/hcsshim logs (logrus global logger).
func initHcnshimFileLogger(path string) string {
// Ensure directory exists
dir := filepath.Dir(path)
if err := os.MkdirAll(dir, 0755); err != nil {
fmt.Println("Failed to create log dir:", err)
return ""
}

// Open file for append (create if missing)
f, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
if err != nil {
fmt.Println("Failed to open log file:", err)
return ""
}

// Configure global logrus (used by hcsshim)
logrus.SetOutput(f)
logrus.SetFormatter(&logrus.TextFormatter{
FullTimestamp: true,
TimestampFormat: "2006-01-02 15:04:05",
})
logrus.SetReportCaller(true) // include file:line
logrus.SetLevel(logrus.DebugLevel) // verbose for testing

fmt.Println("HCN shim logs redirected to:", path)
return "success"
}

var (
CNILogger = initZapLog(zapCNILogFile)
IPamLogger = initZapLog(zapIpamLogFile)
TelemetryLogger = initZapLog(zapTelemetryLogFile)
logrusLogger = initHcnshimFileLogger(`C:\hcnshim.log`)
)
69 changes: 69 additions & 0 deletions cni/network/invoker_cns.go
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,7 @@ type IPResultInfo struct {
routes []cns.Route
pnpID string
endpointPolicies []policy.Policy
secondaryIPs map[string]cns.SecondaryIPConfig
}

func (i IPResultInfo) MarshalLogObject(encoder zapcore.ObjectEncoder) error {
Expand Down Expand Up @@ -92,6 +93,8 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro
PodNamespace: invoker.podNamespace,
}

logger.Debug("Himel testing Add, I think we are in here")

orchestratorContext, err := json.Marshal(podInfo)
if err != nil {
logger.Info(podInfo.PodName)
Expand Down Expand Up @@ -143,6 +146,7 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro
return IPAMAddResult{}, errors.Wrap(err, "Failed to get IP address from CNS")
}
}
logger.Debug("[Add]Himel testing: ", zap.Any("response", response))

addResult := IPAMAddResult{interfaceInfo: make(map[string]network.InterfaceInfo)}
numInterfacesWithDefaultRoutes := 0
Expand All @@ -162,6 +166,7 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro
routes: response.PodIPInfo[i].Routes,
pnpID: response.PodIPInfo[i].PnPID,
endpointPolicies: response.PodIPInfo[i].EndpointPolicies,
secondaryIPs: response.PodIPInfo[i].SecondaryIPConfigs,
}

logger.Info("Received info for pod",
Expand All @@ -173,6 +178,8 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro
key := invoker.getInterfaceInfoKey(info.nicType, info.macAddress)
switch info.nicType {
case cns.NodeNetworkInterfaceFrontendNIC:
logger.Debug("Himel testing Add: we should be frontend")

// only handling single v4 PodIPInfo for NodeNetworkInterfaceFrontendNIC and AccelnetNIC at the moment, will have to update once v6 gets added
if !info.skipDefaultRoutes {
numInterfacesWithDefaultRoutes++
Expand Down Expand Up @@ -219,6 +226,8 @@ func (invoker *CNSIPAMInvoker) Add(addConfig IPAMAddConfig) (IPAMAddResult, erro
return IPAMAddResult{}, errInvalidDefaultRouting
}

logger.Debug("[Add]Himel testing, logging after loop: ", zap.Any("addResult", addResult))

return addResult, nil
}

Expand Down Expand Up @@ -505,9 +514,69 @@ func configureSecondaryAddResult(info *IPResultInfo, addResult *IPAMAddResult, p
SkipDefaultRoutes: info.skipDefaultRoutes,
}

logger.Debug("[configureSecondaryAddResult]Himel before: ", zap.Any("addResult", addResult))

if len(info.secondaryIPs) > 0 {
secIPConfig, err := BuildIPConfigForV6(info.secondaryIPs)

if err == nil {
// If BuildIPConfigForV6 returns a value, take its address
ifaceInfo := addResult.interfaceInfo[key]
ifaceInfo.IPConfigs = append(ifaceInfo.IPConfigs, &secIPConfig)
addResult.interfaceInfo[key] = ifaceInfo
}
}

logger.Debug("[configureSecondaryAddResult]Himel after: ", zap.Any("addResult", addResult))

return nil
}

// Himel hack
// BuildIPConfigForV6 takes SecondaryIPConfigs and returns an IPConfig.
// Assumes map has at least one element and uses the first one found.

func BuildIPConfigForV6(secondaryIPs map[string]cns.SecondaryIPConfig) (network.IPConfig, error) {
for _, v := range secondaryIPs {
ip, ipNet, err := net.ParseCIDR(v.IPAddress)
if err != nil {
return network.IPConfig{}, fmt.Errorf("invalid IPAddress %q: %w", v.IPAddress, err)
}
if ip.To4() != nil {
return network.IPConfig{}, fmt.Errorf("expected IPv6, got IPv4: %q", v.IPAddress)
}

// Preserve the original address/prefix (often /128) for the endpoint.
addr := *ipNet

// Compute the gateway from the /64 network:
// If the parsed mask is /128, swap to /64 for the base; otherwise if already <= /64, use it.
ones, bits := ipNet.Mask.Size()
gwMask := ipNet.Mask
if ones > 64 { // e.g., /128
gwMask = net.CIDRMask(64, bits)
}

// Base = ip masked with /64
base := ip.Mask(gwMask).To16()
if base == nil {
return network.IPConfig{}, fmt.Errorf("failed to get 16-byte IPv6 for %q", v.IPAddress)
}

// Set gateway to ...:...:...:1 (i.e., last byte = 1)
gw := make(net.IP, len(base))
copy(gw, base)
gw[15] = 0x01 // ::1 within that /64

return network.IPConfig{
Address: addr, // original ipNet (likely /128)
Gateway: gw, // derived from /64 base
}, nil
}

return network.IPConfig{}, fmt.Errorf("map is empty")
}

func addBackendNICToResult(info *IPResultInfo, addResult *IPAMAddResult, key string) error {
macAddress, err := net.ParseMAC(info.macAddress)
if err != nil {
Expand Down
16 changes: 15 additions & 1 deletion cni/network/network.go
Original file line number Diff line number Diff line change
Expand Up @@ -494,6 +494,7 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error {
ipamAddConfig := IPAMAddConfig{nwCfg: nwCfg, args: args, options: options}

if nwCfg.MultiTenancy {
logger.Debug("[Add] Was Himel ever here?")
// triggered only in swift v1 multitenancy
// dual nic multitenancy -> two interface infos
// multitenancy (swift v1) -> one interface info
Expand Down Expand Up @@ -524,6 +525,8 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error {
}
} else {
// when nwcfg.multitenancy (use multitenancy flag for swift v1 only) is false
logger.Debug("[Add] Himel should be here")

if plugin.ipamInvoker == nil {
switch nwCfg.IPAM.Type {
case network.AzureCNS:
Expand Down Expand Up @@ -560,13 +563,21 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error {
infraSeen := false
endpointIndex := 1

logger.Debug("[Add] Himel: ", zap.Any("ipamAddResult", ipamAddResult))

for key := range ipamAddResult.interfaceInfo {
ifInfo := ipamAddResult.interfaceInfo[key]
logger.Info("Processing interfaceInfo:", zap.Any("ifInfo", ifInfo))

natInfo := getNATInfo(nwCfg, options[network.SNATIPKey], enableSnatForDNS)
networkID, _ := plugin.getNetworkID(args.Netns, &ifInfo, nwCfg)

isIPv6 := ipamAddResult.ipv6Enabled
// if len(ifInfo.IPConfigs) > 1 {
// logger.Debug("[Add] Himel: I expect we see multiple configs here only for my IPv6 stuff ")
// isIPv6 = true
// }

createEpInfoOpt := createEpInfoOpt{
nwCfg: nwCfg,
cnsNetworkConfig: ifInfo.NCResponse,
Expand All @@ -582,7 +593,7 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error {
networkID: networkID,
ifInfo: &ifInfo,
ipamAddConfig: &ipamAddConfig,
ipv6Enabled: ipamAddResult.ipv6Enabled,
ipv6Enabled: isIPv6,
infraSeen: &infraSeen,
endpointIndex: endpointIndex,
}
Expand All @@ -599,6 +610,9 @@ func (plugin *NetPlugin) Add(args *cniSkel.CmdArgs) error {
// ipamAddResult.interfaceInfo[ifIndex].IPConfigs, epInfo.Data[network.VlanIDKey], k8sPodName, k8sNamespace, plugin.nm.GetNumberOfEndpoints("", nwCfg.Name)))
endpointIndex++
}

logger.Debug("[Add] Himel: ", zap.Any("epInfos", epInfos))

cnsclient, err := cnscli.New(nwCfg.CNSUrl, defaultRequestTimeout)
if err != nil {
return errors.Wrap(err, "failed to create cns client")
Expand Down
1 change: 1 addition & 0 deletions cns/NetworkContainerContract.go
Original file line number Diff line number Diff line change
Expand Up @@ -503,6 +503,7 @@ type GetNetworkContainerResponse struct {

type PodIpInfo struct {
PodIPConfig IPSubnet
SecondaryIPConfigs map[string]SecondaryIPConfig // uuid is key
NetworkContainerPrimaryIPConfig IPConfiguration
HostPrimaryIPInfo HostIPInfo
NICType NICType
Expand Down
32 changes: 31 additions & 1 deletion cns/restserver/ipam.go
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,8 @@ func (service *HTTPRestService) requestIPConfigHandlerHelper(ctx context.Context
}
}

logger.Printf("[requestIPConfigHandlerHelper][Himel] podIPInfoResult: %+v", podIPInfoResult)

// record a pod requesting an IP
service.podsPendingIPAssignment.Push(podInfo.Key())
podIPInfo, err := requestIPConfigsHelper(service, ipconfigsRequest) //nolint:contextcheck // appease linter for revert PR
Expand All @@ -84,6 +86,8 @@ func (service *HTTPRestService) requestIPConfigHandlerHelper(ctx context.Context
}, err
}

logger.Printf("[requestIPConfigHandlerHelper][Himel] podIPInfo: %+v", podIPInfo)

// record a pod assigned an IP
defer func() {
// observe IP assignment wait time
Expand Down Expand Up @@ -128,6 +132,9 @@ func (service *HTTPRestService) requestIPConfigHandlerHelperStandalone(ctx conte
}, errors.New("failed to validate ip config request or unmarshal orchestratorContext")
}

logger.Printf("[requestIPConfigHandlerHelperStandalone][Himel] podInfo: %+v", podInfo)
logger.Printf("[requestIPConfigHandlerHelperStandalone][Himel] ipconfigsRequest: %+v", ipconfigsRequest)

orchestratorContext, err := podInfo.OrchestratorContext()
if err != nil {
return &cns.IPConfigsResponse{}, fmt.Errorf("error getting orchestrator context from PodInfo %w", err)
Expand All @@ -137,7 +144,7 @@ func (service *HTTPRestService) requestIPConfigHandlerHelperStandalone(ctx conte
// IMPORTANT: although SwiftV2 reuses the concept of NCs, NMAgent doesn't program NCs for SwiftV2, but
// instead programs NICs. When getting SwiftV2 NCs, we want the NIC type and MAC address of the NCs.
// TODO: we need another way to verify and sync NMAgent's NIC programming status. pending new NMAgent API or NIC programming status to be passed in the SwiftV2 create NC request.
resp := service.getAllNetworkContainerResponses(cnsRequest) //nolint:contextcheck // not passed in any methods, appease linter
resp, respCreateRequest := service.getAllNetworkContainerResponsesHimel(cnsRequest) //nolint:contextcheck // not passed in any methods, appease linter
// return err if returned list has no NCs
if len(resp) == 0 {
return &cns.IPConfigsResponse{
Expand All @@ -148,6 +155,9 @@ func (service *HTTPRestService) requestIPConfigHandlerHelperStandalone(ctx conte
}, ErrGetAllNCResponseEmpty
}

logger.Printf("[requestIPConfigHandlerHelperStandalone][Himel] resp: %+v", resp)
logger.Printf("[requestIPConfigHandlerHelperStandalone][Himel] respCreateRequest: %+v", respCreateRequest)

// assign NICType and MAC Address for SwiftV2. we assume that there won't be any SwiftV1 NCs here
podIPInfoList := make([]cns.PodIpInfo, 0, len(resp))
for i := range resp {
Expand All @@ -156,10 +166,13 @@ func (service *HTTPRestService) requestIPConfigHandlerHelperStandalone(ctx conte
MacAddress: resp[i].NetworkInterfaceInfo.MACAddress,
NICType: resp[i].NetworkInterfaceInfo.NICType,
NetworkContainerPrimaryIPConfig: resp[i].IPConfiguration,
SecondaryIPConfigs: respCreateRequest[i].SecondaryIPConfigs,
}
podIPInfoList = append(podIPInfoList, podIPInfo)
}

logger.Printf("[requestIPConfigHandlerHelperStandalone][Himel] podIPInfoList: %+v", podIPInfoList)

ipConfigsResp := &cns.IPConfigsResponse{
Response: cns.Response{
ReturnCode: types.Success,
Expand All @@ -176,6 +189,9 @@ func (service *HTTPRestService) requestIPConfigHandlerHelperStandalone(ctx conte
},
}, err
}

logger.Printf("[requestIPConfigHandlerHelperStandalone][Himel] ipConfigsResp: %+v", ipConfigsResp)

return ipConfigsResp, nil
}

Expand Down Expand Up @@ -283,23 +299,31 @@ func (service *HTTPRestService) RequestIPConfigsHandler(w http.ResponseWriter, r
}
var ipConfigsResp *cns.IPConfigsResponse

logger.Printf("[RequestIPConfigsHandler][Himel] ipconfigsRequest: %+v", ipconfigsRequest)
logger.Printf("[RequestIPConfigsHandler][Himel] service: %+v", service)

// Check if IPConfigsHandlerMiddleware is set
if service.IPConfigsHandlerMiddleware != nil {
logger.Printf("Himel testing middleware:")
// Wrap the default datapath handlers with the middleware depending on middleware type
var wrappedHandler cns.IPConfigsHandlerFunc
switch service.IPConfigsHandlerMiddleware.Type() {
case cns.K8sSWIFTV2:
wrappedHandler = service.IPConfigsHandlerMiddleware.IPConfigsRequestHandlerWrapper(service.requestIPConfigHandlerHelper, service.ReleaseIPConfigHandlerHelper)
// this middleware is used for standalone swiftv2 secenario where a different helper is invoked as the PodInfo is read from cns state
case cns.StandaloneSWIFTV2:
logger.Printf("Himel testing middleware standalone")
wrappedHandler = service.IPConfigsHandlerMiddleware.IPConfigsRequestHandlerWrapper(service.requestIPConfigHandlerHelperStandalone, nil)
}

ipConfigsResp, err = wrappedHandler(r.Context(), ipconfigsRequest)
} else {
logger.Printf("Himel testing no middleware:")
ipConfigsResp, err = service.requestIPConfigHandlerHelper(r.Context(), ipconfigsRequest) // nolint:contextcheck // appease linter
}

logger.Printf("[RequestIPConfigsHandler][Himel] ipConfigsResp: %+v", ipConfigsResp)

if err != nil {
w.Header().Set(cnsReturnCode, ipConfigsResp.Response.ReturnCode.String())
err = common.Encode(w, &ipConfigsResp)
Expand Down Expand Up @@ -1002,6 +1026,9 @@ func (service *HTTPRestService) AssignAvailableIPConfigs(podInfo cns.PodInfo) ([

// Get the actual IP families map for validation
ncIPFamilies := service.getIPFamiliesMap()
logger.Printf("[AssignAvailableIPConfigs][Himel] ncIPFamilies: %+v", ncIPFamilies)
logger.Printf("[AssignAvailableIPConfigs][Himel] numberOfIPs: %+v", numberOfIPs)
logger.Printf("[AssignAvailableIPConfigs][Himel] service.PodIPConfigState: %+v", service.PodIPConfigState)

service.Lock()
defer service.Unlock()
Expand Down Expand Up @@ -1371,6 +1398,9 @@ func (service *HTTPRestService) getIPFamiliesMap() map[cns.IPFamily]struct{} {
if len(ncIPFamilies) == 2 {
break
}

logger.Printf("[getIPFamiliesMap][Himel] secIPConfig: %+v", secIPConfig)

addr, err := netip.ParseAddr(secIPConfig.IPAddress)
if err != nil {
continue
Expand Down
Loading